Commit 5f440d2a authored by Geoff Simmons's avatar Geoff Simmons

- bugfixes, make check passes

- Varnish:hitmiss and :handling are working again
- states of data objects are tracked more strictly
parent e0413fdc
......@@ -35,6 +35,7 @@
#include <errno.h>
#include <strings.h>
#include <ctype.h>
#include <stddef.h>
#include "varnishevent.h"
#include "data.h"
......@@ -43,20 +44,27 @@
#include "miniobj.h"
#include "vqueue.h"
#include "vsb.h"
#include "vmb.h"
#define __offsetof(st, m) offsetof(st,m)
/* Preprend head2 before head1, result in head1, head2 empty afterward */
#define VSTAILQ_PREPEND(head1, head2) do { \
#define VSTAILQ_PREPEND(head1, head2, type, fld) do { \
if (VSTAILQ_EMPTY((head2))) \
break; \
if (VSTAILQ_EMPTY((head1))) \
(head1)->vstqh_last = (head2)->vstqh_last; \
else \
*(head2)->vstqh_last = VSTAILQ_FIRST((head1)); \
else { \
struct type *l = VSTAILQ_LAST(head2, type, fld); \
VSTAILQ_NEXT(l, fld) = VSTAILQ_FIRST((head1)); \
} \
VSTAILQ_FIRST((head1)) = VSTAILQ_FIRST((head2)); \
VSTAILQ_INIT((head2)); \
} while (0)
static const char *statename[3] = { "EMPTY", "OCCUPIED" };
static const char *statename[] = {
"FREE", "OPEN", "DONE", "SUBMITTED", "FORMATTING", "WRITTEN"
};
static pthread_mutex_t freetx_lock = PTHREAD_MUTEX_INITIALIZER;
static pthread_mutex_t freerec_lock = PTHREAD_MUTEX_INITIALIZER;
......@@ -69,11 +77,11 @@ static chunkhead_t freechunkhead;
static char bogus_rec;
rec_t * const magic_end_rec = (rec_t * const) &bogus_rec;
/* XXX update for new structures */
static void
data_Cleanup(void)
{
free(txn);
free(rec_nodes);
free(records);
free(chunks);
free(bufptr);
......@@ -90,11 +98,10 @@ data_clear_rec(rec_t *rec, rechead_t * const freerec,
unsigned nchunk = 0;
CHECK_OBJ_NOTNULL(rec, RECORD_MAGIC);
rec->occupied = 0;
rec->tag = SLT__Bogus;
rec->len = 0;
assert(OCCUPIED(rec));
while ((chunk = VSTAILQ_FIRST(&rec->chunks)) != NULL) {
CHECK_OBJ(chunk, CHUNK_MAGIC);
assert(OCCUPIED(chunk));
chunk->occupied = 0;
*chunk->data = '\0';
VSTAILQ_REMOVE_HEAD(&rec->chunks, chunklist);
......@@ -102,6 +109,9 @@ data_clear_rec(rec_t *rec, rechead_t * const freerec,
nchunk++;
}
assert(VSTAILQ_EMPTY(&rec->chunks));
rec->tag = SLT__Bogus;
rec->len = 0;
rec->occupied = 0;
VSTAILQ_INSERT_HEAD(freerec, rec, freelist);
return nchunk;
}
......@@ -113,21 +123,22 @@ DATA_Clear_Tx(tx_t * const tx, txhead_t * const freetx,
unsigned * restrict const nfree_rec,
unsigned * restrict const nfree_chunk)
{
rec_t *rec;
unsigned nchunk = 0, nrec = 0;
CHECK_OBJ_NOTNULL(tx, TX_MAGIC);
assert(tx->state == TX_WRITTEN);
tx->occupied = 0;
tx->vxid = -1;
tx->pvxid = -1;
tx->type = VSL_t_unknown;
tx->t = 0.;
tx->disp = DISP_NONE;
for (int i = 0; i <= max_idx; i++) {
for (int i = 0; i < max_idx; i++) {
rec_node_t *rec_node = tx->recs[i];
CHECK_OBJ_NOTNULL(rec_node, REC_NODE_MAGIC);
if (rec_node->rec != NULL) {
CHECK_OBJ(rec_node->rec, RECORD_MAGIC);
nchunk += data_clear_rec(rec_node->rec, freerec, freechunk);
nrec++;
rec_node->rec = NULL;
......@@ -135,13 +146,17 @@ DATA_Clear_Tx(tx_t * const tx, txhead_t * const freetx,
}
if (rec_node->hdrs == NULL)
continue;
for (int j = 0; rec_node->hdrs[j] != magic_end_rec; j++)
for (int j = 0; rec_node->hdrs[j] != magic_end_rec; j++) {
rec_t *rec;
if ((rec = rec_node->hdrs[j]) != NULL) {
CHECK_OBJ(rec, RECORD_MAGIC);
nchunk += data_clear_rec(rec, freerec, freechunk);
nrec++;
rec_node->hdrs[j] = NULL;
}
}
}
tx->state = TX_FREE;
VSTAILQ_INSERT_HEAD(freetx, tx, freelist);
*nfree_tx += 1;
*nfree_rec += nrec;
......@@ -227,15 +242,15 @@ DATA_Init(void)
VSTAILQ_INIT(&freetxhead);
for (int i = 0; i < config.max_data; i++) {
txn[i].magic = TX_MAGIC;
txn[i].occupied = 0;
txn[i].state = TX_FREE;
txn[i].vxid = -1;
txn[i].pvxid = -1;
txn[i].type = VSL_t_unknown;
txn[i].t = 0.;
txn[i].recs = (rec_node_t **) malloc((max_idx + 1)
* sizeof(rec_node_t *));
txn[i].disp = DISP_NONE;
txn[i].recs = (rec_node_t **) malloc(max_idx * sizeof(rec_node_t *));
AN(txn[i].recs);
for (int j = 0; j <= max_idx; j++) {
for (int j = 0; j < max_idx; j++) {
assert((i * max_idx) + j < nrecnodes);
txn[i].recs[j] = &rec_nodes[(i * max_idx) + j];
CHECK_OBJ(txn[i].recs[j], REC_NODE_MAGIC);
......@@ -247,7 +262,7 @@ DATA_Init(void)
idx = tag2idx[j];
if (idx == -1)
continue;
assert(idx <= max_idx);
assert(idx < max_idx);
if ((inc = hdr_include_tbl[j]) == NULL) {
txn[i].recs[idx]->hdrs = NULL;
continue;
......@@ -323,7 +338,7 @@ DATA_Take_Free##type(struct type##head_s *dst) \
unsigned nfree; \
\
AZ(pthread_mutex_lock(&free##type##_lock)); \
VSTAILQ_PREPEND(dst, &free##type##head); \
VSTAILQ_PREPEND(dst, &free##type##head, type##_t, freelist); \
nfree = global_nfree_##type; \
global_nfree_##type = 0; \
AZ(pthread_mutex_unlock(&free##type##_lock)); \
......@@ -343,7 +358,7 @@ void \
DATA_Return_Free##type(struct type##head_s *returned, unsigned nreturned) \
{ \
AZ(pthread_mutex_lock(&free##type##_lock)); \
VSTAILQ_PREPEND(&free##type##head, returned); \
VSTAILQ_PREPEND(&free##type##head, returned, type##_t, freelist); \
global_nfree_##type += nreturned; \
AZ(pthread_mutex_unlock(&free##type##_lock)); \
}
......@@ -408,7 +423,7 @@ DATA_Dump(void)
continue;
}
if (txn[i].occupied == 0)
if (txn[i].state == TX_FREE)
continue;
tx = &txn[i];
......@@ -416,10 +431,10 @@ DATA_Dump(void)
VSB_printf(data,
"Tx entry %d: vxid=%u pvxid=%d state=%s dir=%c records={",
i, tx->vxid, tx->pvxid, statename[tx->occupied],
i, tx->vxid, tx->pvxid, statename[tx->state],
C(tx->type) ? 'c' : B(tx->type) ? 'b' : '-');
for (int j = 0; j <= max_idx; j++) {
for (int j = 0; j < max_idx; j++) {
rec_t *rec;
rec_node = tx->recs[j];
......@@ -436,7 +451,7 @@ DATA_Dump(void)
}
if (rec_node->hdrs == NULL)
continue;
for (int k = 0; k <= max_idx; k++) {
for (int k = 0; rec_node->hdrs[k] != magic_end_rec; k++) {
rec = rec_node->hdrs[k];
if (rec == NULL)
continue;
......
This diff is collapsed.
......@@ -98,9 +98,7 @@ formatter_f format_Xt;
formatter_f format_Xttfb_client;
formatter_f format_Xttfb_backend;
#if 0
formatter_f format_VCL_disp;
#endif
formatter_f format_VCL_Log;
......
......@@ -23,7 +23,7 @@ fi
# predictable from one run to the next.
CKSUM=$( sed -e 's/\(initializing\) \(.*\)/\1/' $LOG | egrep -v 'Writer: returned|Reader: took|^DEBUG: Allocating' | cksum )
if [ "$CKSUM" != '3182678025 71888971' ]; then
if [ "$CKSUM" != '2449935941 61504698' ]; then
echo "ERROR: Regression test varnishevent log incorrect cksum: $CKSUM"
exit 1
fi
......
......@@ -74,12 +74,13 @@ static char
for (int i = 0; i < config.max_data; i++) {
MCHECK_OBJ(&txn[i], TX_MAGIC);
MASSERT(!OCCUPIED(&txn[i]));
MASSERT(txn[i].state == TX_FREE);
MASSERT(txn[i].vxid == -1);
MASSERT(txn[i].pvxid == -1);
MASSERT(txn[i].type == VSL_t_unknown);
MASSERT(txn[i].disp == DISP_NONE);
MAZ(txn[i].t);
for (int j = 0; j <= max_idx; j++) {
for (int j = 0; j < max_idx; j++) {
MCHECK_OBJ_NOTNULL(txn[i].recs[j], REC_NODE_MAGIC);
MAZ(txn[i].recs[j]->rec);
if (txn[i].recs[j]->hdrs != NULL)
......@@ -292,6 +293,7 @@ fill_rec(rec_t *rec, chunk_t *c, int nc)
VSTAILQ_INSERT_TAIL(&rec->chunks, chunk, chunklist);
chunk->magic = CHUNK_MAGIC;
chunk->data = (char *) calloc(1, config.chunk_size);
chunk->occupied = 1;
chunks_filled++;
}
}
......@@ -329,7 +331,7 @@ static const char
#define N_NODES (max_idx + 1)
#define HDRS_PER_NODE 5
#define CHUNKS_PER_REC 3
#define NRECS ((N_NODES)/2 + (((N_NODES) - (N_NODES)/2) * HDRS_PER_NODE))
#define NRECS ((max_idx)/2 + (((max_idx) - (max_idx)/2) * HDRS_PER_NODE))
#define NCHUNKS ((NRECS) * (CHUNKS_PER_REC))
tx_t tx;
rec_t *rec;
......@@ -348,10 +350,11 @@ static const char
tx.vxid = 314159265;
tx.pvxid = 2718281828;
tx.type = VSL_t_req;
tx.occupied = 1;
tx.recs = (rec_node_t **) calloc(N_NODES, sizeof(rec_node_t *));
tx.state = TX_WRITTEN;
tx.disp = DISP_HIT;
tx.recs = (rec_node_t **) calloc(max_idx, sizeof(rec_node_t *));
MAN(tx.recs);
for (int i = 0; i < N_NODES/2; i++) {
for (int i = 0; i < max_idx/2; i++) {
tx.recs[i] = &rec_nodes[i];
rec_nodes[i].magic = REC_NODE_MAGIC;
rec_nodes[i].rec = &records[i];
......@@ -360,7 +363,7 @@ static const char
== VSTAILQ_LAST(&records[i].chunks, chunk_t, chunklist));
rec_nodes[i].hdrs = NULL;
}
for (int i = N_NODES/2; i < N_NODES; i++) {
for (int i = max_idx/2; i < max_idx; i++) {
tx.recs[i] = &rec_nodes[i];
rec_nodes[i].magic = REC_NODE_MAGIC;
rec_nodes[i].rec = NULL;
......@@ -368,7 +371,7 @@ static const char
sizeof(rec_t *));
MAN(rec_nodes[i].hdrs);
for (int j = 0; j < HDRS_PER_NODE; j++) {
int idx = N_NODES/2 + (i - N_NODES/2) * HDRS_PER_NODE + j;
int idx = max_idx/2 + (i - max_idx/2) * HDRS_PER_NODE + j;
rec_nodes[i].hdrs[j] = &records[idx];
fill_rec(&records[idx], &chunks[idx * CHUNKS_PER_REC],
CHUNKS_PER_REC);
......@@ -384,12 +387,13 @@ static const char
MASSERT(nfree_chunks == 1147 + NCHUNKS);
MCHECK_OBJ(&tx, TX_MAGIC);
MASSERT(!OCCUPIED(&tx));
MASSERT(tx.state == TX_FREE);
MASSERT(tx.vxid == -1);
MASSERT(tx.pvxid == -1);
MASSERT(tx.type == VSL_t_unknown);
MASSERT(tx.disp == DISP_NONE);
MAZ(tx.t);
for (int i = 0; i < N_NODES; i++) {
for (int i = 0; i < max_idx; i++) {
REC_NODE_CLEARED(tx.recs[i]);
REC_NODE_CLEARED(&rec_nodes[i]);
}
......
This diff is collapsed.
......@@ -52,8 +52,7 @@ static char
*test_timeout(void)
{
tx_t tx;
rec_t rec;
chunk_t chunk;
rec_node_t node, *nptr[1];
printf("... testing write timeouts\n");
......@@ -72,18 +71,15 @@ static char
VSTAILQ_INIT(&wrt_freetx);
MASSERT(VSTAILQ_EMPTY(&wrt_freetx));
/* XXX: common helper functions with test_format */
tx.magic = TX_MAGIC;
VSTAILQ_INIT(&tx.recs);
VSTAILQ_INSERT_TAIL(&tx.recs, &rec, reclist);
rec.magic = RECORD_MAGIC;
VSTAILQ_INIT(&rec.chunks);
VSTAILQ_INSERT_TAIL(&rec.chunks, &chunk, chunklist);
chunk.magic = CHUNK_MAGIC;
chunk.data = (char *) calloc(1, config.chunk_size);
tx.recs = nptr;
nptr[0] = &node;
node.magic = REC_NODE_MAGIC;
node.rec = NULL;
node.hdrs = NULL;
for (int i = 0; i < THRESHOLD; i++) {
tx.occupied = 1;
tx.state = TX_SUBMITTED;
tx.type = VSL_t_req;
wrt_write(&tx);
......
......@@ -217,7 +217,9 @@ static inline tx_t
}
tx_exhausted = 0;
tx = VSTAILQ_FIRST(&rdr_tx_freelist);
assert(tx->state == TX_FREE);
VSTAILQ_REMOVE_HEAD(&rdr_tx_freelist, freelist);
tx->state = TX_OPEN;
rdr_tx_free--;
return (tx);
......@@ -235,7 +237,8 @@ static inline void
submit(tx_t *tx)
{
CHECK_OBJ_NOTNULL(tx, TX_MAGIC);
assert(OCCUPIED(tx));
assert(tx->state == TX_DONE);
tx->state = TX_SUBMITTED;
VWMB();
SPSCQ_Enq(tx);
signal_spscq_ready();
......@@ -267,7 +270,8 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv)
continue;
}
CHECK_OBJ_NOTNULL(tx, TX_MAGIC);
assert(!OCCUPIED(tx));
assert(tx->state == TX_OPEN);
assert(tx->disp == DISP_NONE);
AN(tx->recs);
tx->type = t->type;
tx->vxid = t->vxid;
......@@ -284,13 +288,38 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv)
if ((idx = tag2idx[VSL_TAG(t->c->rec.ptr)]) == -1)
continue;
tag = VSL_TAG(t->c->rec.ptr);
p = (const char *) VSL_CDATA(t->c->rec.ptr);
len = VSL_LEN(t->c->rec.ptr);
switch(tag) {
case SLT_VCL_call:
case SLT_VCL_return:
if (tx->disp != DISP_NONE)
continue;
if (strncasecmp("hit", p, len) == 0)
tx->disp = DISP_HIT;
else if (strncasecmp("miss", p, len) == 0)
tx->disp = DISP_MISS;
else if (strncasecmp("pass", p, len) == 0)
tx->disp = DISP_PASS;
else if (strncasecmp("error", p, len) == 0)
tx->disp = DISP_ERROR;
else if (strncasecmp("pipe", p, len) == 0)
tx->disp = DISP_PIPE;
if (debug && tx->disp != DISP_NONE)
LOG_Log(LOG_DEBUG, "Record: [%u %s %.*s]",
VSL_ID(t->c->rec.ptr), VSL_tags[tag], len, p);
continue;
default:
break;
}
CHECK_OBJ_NOTNULL(tx->recs[idx], REC_NODE_MAGIC);
if (tx->recs[idx]->rec != NULL)
continue;
if (tx->recs[idx]->hdrs != NULL) {
hdr_idx = DATA_FindHdrIdx(VSL_TAG(t->c->rec.ptr),
(const char *)
VSL_CDATA(t->c->rec.ptr));
hdr_idx = DATA_FindHdrIdx(tag, p);
if (hdr_idx == -1)
continue;
if (tx->recs[idx]->hdrs[hdr_idx] != NULL)
......@@ -300,9 +329,6 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv)
else
rp = &tx->recs[idx]->rec;
tag = VSL_TAG(t->c->rec.ptr);
p = (const char *) VSL_CDATA(t->c->rec.ptr);
len = VSL_LEN(t->c->rec.ptr);
if (debug)
LOG_Log(LOG_DEBUG, "Record: [%u %s %.*s]",
VSL_ID(t->c->rec.ptr), VSL_tags[tag], len, p);
......@@ -360,11 +386,17 @@ event(struct VSL_data *vsl, struct VSL_transaction * const pt[], void *priv)
}
if (nrec == 0) {
tx->state = TX_FREE;
tx->type = VSL_t_unknown;
tx->vxid = -1;
tx->pvxid = -1;
tx->t = 0.;
VSTAILQ_INSERT_HEAD(&rdr_tx_freelist, tx, freelist);
continue;
}
tx->occupied = 1;
assert(tx->state == TX_OPEN);
tx->state = TX_DONE;
seen++;
MON_StatsUpdate(STATS_DONE, nrec, total_chunks);
if (tx_occ > tx_occ_hi)
......
......@@ -76,10 +76,10 @@ int max_idx;
typedef struct chunk_t {
unsigned magic;
#define CHUNK_MAGIC 0x676e0d19
unsigned occupied;
char *data;
VSTAILQ_ENTRY(chunk_t) freelist;
VSTAILQ_ENTRY(chunk_t) chunklist;
unsigned int occupied:1;
} chunk_t;
typedef VSTAILQ_HEAD(chunkhead_s, chunk_t) chunkhead_t;
......@@ -91,10 +91,10 @@ typedef struct rec_t {
unsigned magic;
#define RECORD_MAGIC 0xf427a374
unsigned len;
unsigned occupied;
enum VSL_tag_e tag;
chunkhead_t chunks;
VSTAILQ_ENTRY(rec_t) freelist;
enum VSL_tag_e tag;
unsigned int occupied:1;
} rec_t;
rec_t *records;
......@@ -111,17 +111,36 @@ typedef struct rec_node_t {
rec_node_t *rec_nodes;
enum tx_state_e {
TX_FREE,
TX_OPEN,
TX_DONE,
TX_SUBMITTED,
TX_FORMATTING,
TX_WRITTEN
};
enum tx_disp_e {
DISP_NONE = 0,
DISP_HIT,
DISP_MISS,
DISP_PASS,
DISP_PIPE,
DISP_ERROR
};
typedef struct tx_t {
unsigned magic;
#define TX_MAGIC 0xff463e42
VSTAILQ_ENTRY(tx_t) freelist;
VSTAILQ_ENTRY(tx_t) spscq;
rec_node_t **recs;
double t;
int32_t vxid;
int32_t pvxid;
enum VSL_transaction_e type:7;
unsigned int occupied:1;
enum VSL_transaction_e type;
enum tx_state_e state;
enum tx_disp_e disp;
double t;
rec_node_t **recs;
VSTAILQ_ENTRY(tx_t) freelist;
VSTAILQ_ENTRY(tx_t) spscq;
} tx_t;
tx_t *txn;
......
......@@ -140,11 +140,12 @@ open_log(void)
static inline void
wrt_return_freelist(void)
{
if (wrt_nfree_tx > 0) {
DATA_Return_Freetx(&wrt_freetx, wrt_nfree_tx);
LOG_Log(LOG_DEBUG, "Writer: returned %u tx to free list", wrt_nfree_tx);
wrt_nfree_tx = 0;
assert(VSTAILQ_EMPTY(&wrt_freetx));
if (wrt_nfree_chunks > 0) {
DATA_Return_Freechunk(&wrt_freechunks, wrt_nfree_chunks);
LOG_Log(LOG_DEBUG, "Writer: returned %u chunks to free list",
wrt_nfree_chunks);
wrt_nfree_chunks = 0;
assert(VSTAILQ_EMPTY(&wrt_freechunks));
}
if (wrt_nfree_recs > 0) {
DATA_Return_Freerec(&wrt_freerecs, wrt_nfree_recs);
......@@ -153,12 +154,11 @@ wrt_return_freelist(void)
wrt_nfree_recs = 0;
assert(VSTAILQ_EMPTY(&wrt_freerecs));
}
if (wrt_nfree_chunks > 0) {
DATA_Return_Freechunk(&wrt_freechunks, wrt_nfree_chunks);
LOG_Log(LOG_DEBUG, "Writer: returned %u chunks to free list",
wrt_nfree_chunks);
wrt_nfree_chunks = 0;
assert(VSTAILQ_EMPTY(&wrt_freechunks));
if (wrt_nfree_tx > 0) {
DATA_Return_Freetx(&wrt_freetx, wrt_nfree_tx);
LOG_Log(LOG_DEBUG, "Writer: returned %u tx to free list", wrt_nfree_tx);
wrt_nfree_tx = 0;
assert(VSTAILQ_EMPTY(&wrt_freetx));
}
}
......@@ -168,7 +168,7 @@ wrt_write(tx_t *tx)
int errnum;
CHECK_OBJ_NOTNULL(tx, TX_MAGIC);
assert(OCCUPIED(tx));
assert(tx->state == TX_SUBMITTED);
AZ(pthread_mutex_lock(&reopen_lock));
if (reopen && fo != stdout) {
......@@ -194,6 +194,7 @@ wrt_write(tx_t *tx)
VSB_clear(os);
FMT_Format(tx, os);
VSB_finish(os);
assert(tx->state == TX_WRITTEN);
if (timeout != NULL)
to = config.output_timeout;
......@@ -239,6 +240,8 @@ wrt_write(tx_t *tx)
DATA_Clear_Tx(tx, &wrt_freetx, &wrt_freerecs, &wrt_freechunks,
&wrt_nfree_tx, &wrt_nfree_recs, &wrt_nfree_chunks);
assert(tx->state == TX_FREE);
if (RDR_Exhausted() || wrt_nfree_tx > tx_thresh
|| wrt_nfree_recs > rec_thresh || wrt_nfree_chunks > chunk_thresh)
wrt_return_freelist();
......
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment