test_cache_digest.c

-

	(double) 1e6 * tvSubDsec(t_start, t_end) / cache->count);
}

static void
cacheQueryPeer(Cache * cache, const cache_key * key)
{
    const int peer_has_it = hash_lookup(cache->peer->hash, key) != NULL;
    const int we_think_we_have_it = cacheDigestTest(cache->digest, key);

    cache->qstats.query_count++;
    if (peer_has_it) {
	if (we_think_we_have_it)
	    cache->qstats.true_hit_count++;
	else
	    cache->qstats.false_miss_count++;
    } else {
	if (we_think_we_have_it)
	    cache->qstats.false_hit_count++;
	else
	    cache->qstats.true_miss_count++;
    }
}

static void
cacheQueryReport(Cache * cache, CacheQueryStats * stats)
{
    fprintf(stdout, "%s: peer queries: %d (%d%%)\n",
	cache->name,
	stats->query_count, xpercentInt(stats->query_count, cache->req_count)
	);
    fprintf(stdout, "%s: t-hit: %d (%d%%) t-miss: %d (%d%%) t-*: %d (%d%%)\n",
	cache->name,
	stats->true_hit_count, xpercentInt(stats->true_hit_count, stats->query_count),
	stats->true_miss_count, xpercentInt(stats->true_miss_count, stats->query_count),
	stats->true_hit_count + stats->true_miss_count,
	xpercentInt(stats->true_hit_count + stats->true_miss_count, stats->query_count)
	);
    fprintf(stdout, "%s: f-hit: %d (%d%%) f-miss: %d (%d%%) f-*: %d (%d%%)\n",
	cache->name,
	stats->false_hit_count, xpercentInt(stats->false_hit_count, stats->query_count),
	stats->false_miss_count, xpercentInt(stats->false_miss_count, stats->query_count),
	stats->false_hit_count + stats->false_miss_count,
	xpercentInt(stats->false_hit_count + stats->false_miss_count, stats->query_count)
	);
}

static void
cacheReport(Cache * cache)
{
    fprintf(stdout, "%s: entries: %d reqs: %d bad-add: %d bad-del: %d\n",
	cache->name, cache->count, cache->req_count,
	cache->bad_add_count, cache->bad_del_count);

}

static void
cacheFetch(Cache * cache, const RawAccessLogEntry * e)
{
    assert(e);
    cache->req_count++;
    if (e->use_icp)
	cacheQueryPeer(cache, e->key);
}

static fr_result
swapStateReader(FileIterator * fi)
{
    storeSwapLogData *entry;
    if (!fi->entry)
	fi->entry = xcalloc(1, sizeof(storeSwapLogData));
    entry = fi->entry;
    if (fread(entry, sizeof(*entry), 1, fi->file) != 1)
	return frEof;
    fi->inner_time = entry->lastref;
    if (entry->op != SWAP_LOG_ADD && entry->op != SWAP_LOG_DEL) {
	fprintf(stderr, "%s:%d: unknown swap log action\n", fi->fname, fi->line_count);
	exit(-3);
    }
    return frOk;
}

static fr_result
accessLogReader(FileIterator * fi)
{
    static char buf[4096];
    RawAccessLogEntry *entry;
    char *url;
    char *method;
    int method_id = METHOD_NONE;
    char *hier = NULL;

    assert(fi);
    if (!fi->entry)
	fi->entry = xcalloc(1, sizeof(RawAccessLogEntry));
    else
	memset(fi->entry, 0, sizeof(RawAccessLogEntry));
    entry = fi->entry;
    if (!fgets(buf, sizeof(buf), fi->file))
	return frEof;		/* eof */
    entry->timestamp = fi->inner_time = (time_t) atoi(buf);
    url = strstr(buf, "://");
    hier = url ? strstr(url, " - ") : NULL;

    if (!url || !hier) {
	/*fprintf(stderr, "%s:%d: strange access log entry '%s'\n", 
	 * fname, scanned_count, buf); */
	return frError;
    }
    method = url;
    while (!isdigit(*method)) {
	if (*method == ' ')
	    *method = '\0';
	--method;
    }
    method += 2;
    method_id = methodStrToId(method);
    if (method_id == METHOD_NONE) {
	/*fprintf(stderr, "%s:%d: invalid method %s in '%s'\n", 
	 * fname, scanned_count, method, buf); */
	return frError;
    }
    while (*url)
	url--;
    url++;
    *hier = '\0';
    hier += 3;
    *strchr(hier, '/') = '\0';
    /*fprintf(stdout, "%s:%d: %s %s %s\n",
     * fname, count, method, url, hier); */
    entry->use_icp = strcmp(hier, "NONE");
    /* no ICP lookup for these status codes */
/*      strcmp(hier, "NONE") &&
 * strcmp(hier, "DIRECT") &&
 * strcmp(hier, "FIREWALL_IP_DIRECT") &&
 * strcmp(hier, "LOCAL_IP_DIRECT") &&
 * strcmp(hier, "NO_DIRECT_FAIL") &&
 * strcmp(hier, "NO_PARENT_DIRECT") &&
 * strcmp(hier, "SINGLE_PARENT") &&
 * strcmp(hier, "PASSTHROUGH_PARENT") &&
 * strcmp(hier, "SSL_PARENT_MISS") &&
 * strcmp(hier, "DEFAULT_PARENT");
 */
    memcpy(entry->key, storeKeyPublic(url, method_id), sizeof(entry->key));
    /*fprintf(stdout, "%s:%d: %s %s %s %s\n",
     * fname, count, method, storeKeyText(entry->key), url, hier); */
    return frOk;
}


static void
cachePurge(Cache * cache, storeSwapLogData * s, int update_digest)
{
    CacheEntry *olde = (CacheEntry *) hash_lookup(cache->hash, s->key);
    if (!olde) {
	cache->bad_del_count++;
    } else {
	assert(cache->count);
	hash_remove_link(cache->hash, (hash_link *) olde);
	if (update_digest)
	    cacheDigestDel(cache->digest, s->key);
	cacheEntryDestroy(olde);
	cache->count--;
    }
}

static void
cacheStore(Cache * cache, storeSwapLogData * s, int update_digest)
{
    CacheEntry *olde = (CacheEntry *) hash_lookup(cache->hash, s->key);
    if (olde) {
	cache->bad_add_count++;
    } else {
	CacheEntry *e = cacheEntryCreate(s);
	hash_join(cache->hash, (hash_link *) e);
	cache->count++;
	if (update_digest)
	    cacheDigestAdd(cache->digest, e->key);
    }
}

static void
cacheUpdateStore(Cache * cache, storeSwapLogData * s, int update_digest)
{
    switch (s->op) {
    case SWAP_LOG_ADD:
	cacheStore(cache, s, update_digest);
	break;
    case SWAP_LOG_DEL:
	cachePurge(cache, s, update_digest);
	break;
    default:
	assert(0);
    }
}

static int
usage(const char *prg_name)
{
    fprintf(stderr, "usage: %s <access_log> <swap_state> ...\n",
	prg_name);
    return -1;
}

int
main(int argc, char *argv[])
{
    FileIterator **fis = NULL;
    const int fi_count = argc - 1;
    int active_fi_count = 0;
    time_t ready_time;
    Cache *them, *us;
    int i;

    if (argc < 3)
	return usage(argv[0]);

    them = cacheCreate("them");
    us = cacheCreate("us");
    them->peer = us;
    us->peer = them;

    fis = xcalloc(fi_count, sizeof(FileIterator *));
    /* init iterators with files */
    fis[0] = fileIteratorCreate(argv[1], accessLogReader);
    for (i = 2; i < argc; ++i)
	fis[i - 1] = fileIteratorCreate(argv[i], swapStateReader);
    /* check that all files were found */
    for (i = 0; i < fi_count; ++i)
	if (!fis[i])
	    return -2;
    /* read prefix to get start-up contents of the peer cache */
    ready_time = -1;
    for (i = 1; i < fi_count; ++i) {
	FileIterator *fi = fis[i];
	while (fi->inner_time > 0) {
	    if (((storeSwapLogData *) fi->entry)->op == SWAP_LOG_DEL) {
		cachePurge(them, fi->entry, 0);
		if (ready_time < 0)
		    ready_time = fi->inner_time;
	    } else {
		if (ready_time > 0 && fi->inner_time > ready_time)
		    break;
		cacheStore(them, fi->entry, 0);
	    }
	    fileIteratorAdvance(fi);
	}
    }
    /* digest peer cache content */
    cacheResetDigest(them);
    us->digest = cacheDigestClone(them->digest);	/* @netw@ */

    /* shift the time in access log to match ready_time */
    fileIteratorSetCurTime(fis[0], ready_time);

    /* iterate, use the iterator with the smallest positive inner_time */
    cur_time = -1;
    do {
	int next_i = -1;
	time_t next_time = -1;
	active_fi_count = 0;
	for (i = 0; i < fi_count; ++i) {
	    if (fis[i]->inner_time >= 0) {
		if (!active_fi_count || fis[i]->inner_time < next_time) {
		    next_i = i;
		    next_time = fis[i]->inner_time;
		}
		active_fi_count++;
	    }
	}
	if (next_i >= 0) {
	    cur_time = next_time;
	    /*fprintf(stderr, "%2d time: %d %s", next_i, (int)cur_time, ctime(&cur_time)); */
	    if (next_i == 0)
		cacheFetch(us, fis[next_i]->entry);
	    else
		cacheUpdateStore(them, fis[next_i]->entry, 1);
	    fileIteratorAdvance(fis[next_i]);
	}
    } while (active_fi_count);

    /* report */
    cacheReport(them);
    cacheReport(us);
    cacheQueryReport(us, &us->qstats);

    /* clean */
    for (i = 0; i < argc - 1; ++i) {
	fileIteratorDestroy(fis[i]);
    }
    xfree(fis);
    cacheDestroy(them);
    cacheDestroy(us);
    return 0;
}