3 * $Id: test_cache_digest.cc,v 1.35 2008/01/20 08:54:28 amosjeffries Exp $
5 * AUTHOR: Alex Rousskov
7 * SQUID Web Proxy Cache http://www.squid-cache.org/
8 * ----------------------------------------------------------
10 * Squid is the result of efforts by numerous individuals from
11 * the Internet community; see the CONTRIBUTORS file for full
12 * details. Many organizations have provided support for Squid's
13 * development; see the SPONSORS file for full details. Squid is
14 * Copyrighted (C) 2001 by the Regents of the University of
15 * California; see the COPYRIGHT file for full details. Squid
16 * incorporates software developed and/or copyrighted by other
17 * sources; see the CREDITS file for full details.
19 * This program is free software; you can redistribute it and/or modify
20 * it under the terms of the GNU General Public License as published by
21 * the Free Software Foundation; either version 2 of the License, or
22 * (at your option) any later version.
24 * This program is distributed in the hope that it will be useful,
25 * but WITHOUT ANY WARRANTY; without even the implied warranty of
26 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
27 * GNU General Public License for more details.
29 * You should have received a copy of the GNU General Public License
30 * along with this program; if not, write to the Free Software
31 * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
36 * Test-suite for playing with cache digests
49 typedef struct _Cache Cache
;
56 CacheQueryStats qstats
;
57 int count
; /* #currently cached entries */
58 int req_count
; /* #requests to this cache */
59 int bad_add_count
; /* #duplicate adds */
60 int bad_del_count
; /* #dels with no prior add */
64 typedef struct _CacheEntry
{
67 struct _CacheEntry
*next
;
68 unsigned char key_arr
[SQUID_MD5_DIGEST_LENGTH
];
69 /* storeSwapLogData s; */
72 /* parsed access log entry */
75 cache_key key
[SQUID_MD5_DIGEST_LENGTH
];
77 short int use_icp
; /* true/false */
81 frError
= -2, frMore
= -1, frEof
= 0, frOk
= 1
84 typedef struct _FileIterator FileIterator
;
85 typedef fr_result(*FI_READER
) (FileIterator
* fi
);
87 struct _FileIterator
{
90 time_t inner_time
; /* timestamp of the current entry */
91 time_t time_offset
; /* to adjust time set by reader */
92 int line_count
; /* number of lines scanned */
93 int bad_line_count
; /* number of parsing errors */
94 int time_warp_count
; /* number of out-of-order entries in the file */
95 FI_READER reader
; /* reads next entry and updates inner_time */
96 void *entry
; /* buffer for the current entry, freed with xfree() */
100 static time_t cur_time
= -1; /* timestamp of the current log entry */
102 /* copied from url.c */
103 const char *RequestMethodStr
[] = {
114 /* copied from url.c */
115 static HttpRequestMethod
116 methodStrToId(const char *s
)
118 if (strcasecmp(s
, "GET") == 0) {
120 } else if (strcasecmp(s
, "POST") == 0) {
122 } else if (strcasecmp(s
, "PUT") == 0) {
124 } else if (strcasecmp(s
, "HEAD") == 0) {
126 } else if (strcasecmp(s
, "CONNECT") == 0) {
127 return METHOD_CONNECT
;
128 } else if (strcasecmp(s
, "TRACE") == 0) {
130 } else if (strcasecmp(s
, "PURGE") == 0) {
139 static void fileIteratorAdvance(FileIterator
* fi
);
141 static FileIterator
*
142 fileIteratorCreate(const char *fname
, FI_READER reader
)
144 FileIterator
*fi
= (FileIterator
*)xcalloc(1, sizeof(FileIterator
));
145 assert(fname
&& reader
);
148 fi
->file
= fopen(fname
, "r");
151 fprintf(stderr
, "cannot open %s: %s\n", fname
, strerror(errno
));
154 fprintf(stderr
, "opened %s\n", fname
);
156 fileIteratorAdvance(fi
);
162 fileIteratorDestroy(FileIterator
* fi
)
168 fprintf(stderr
, "closed %s\n", fi
->fname
);
176 fileIteratorSetCurTime(FileIterator
* fi
, time_t ct
)
179 assert(fi
->inner_time
> 0);
180 fi
->time_offset
= ct
- fi
->inner_time
;
184 fileIteratorAdvance(FileIterator
* fi
)
190 const time_t last_time
= fi
->inner_time
;
192 res
= fi
->reader(fi
);
195 if (fi
->inner_time
< 0)
196 fi
->inner_time
= last_time
;
198 fi
->inner_time
+= fi
->time_offset
;
201 fi
->bad_line_count
++;
202 else if (res
== frEof
) {
203 fprintf(stderr
, "exhausted %s (%d entries) at %s",
204 fi
->fname
, fi
->line_count
, ctime(&fi
->inner_time
));
206 } else if (fi
->inner_time
< last_time
) {
207 assert(last_time
>= 0);
208 fi
->time_warp_count
++;
209 fi
->inner_time
= last_time
;
212 /* report progress */
213 if (!(fi
->line_count
% 50000))
214 fprintf(stderr
, "%s scanned %d K entries (%d bad) at %s",
215 fi
->fname
, fi
->line_count
/ 1000, fi
->bad_line_count
,
216 ctime(&fi
->inner_time
));
223 cacheEntryCreate(const storeSwapLogData
* s
)
225 CacheEntry
*e
= (CacheEntry
*)xcalloc(1, sizeof(CacheEntry
));
228 xmemcpy(e
->key_arr
, s
->key
, SQUID_MD5_DIGEST_LENGTH
);
229 e
->key
= &e
->key_arr
[0];
234 cacheEntryDestroy(CacheEntry
* e
)
244 cacheCreate(const char *name
)
247 assert(name
&& strlen(name
));
248 c
= (Cache
*)xcalloc(1, sizeof(Cache
));
250 c
->hash
= hash_create(storeKeyHashCmp
, (int)2e6
, storeKeyHashHash
);
255 cacheDestroy(Cache
* cache
)
257 CacheEntry
*e
= NULL
;
261 /* destroy hash table contents */
264 while ((e
= (CacheEntry
*)hash_next(hash
))) {
265 hash_remove_link(hash
, (hash_link
*) e
);
266 cacheEntryDestroy(e
);
269 /* destroy the hash table itself */
270 hashFreeMemory(hash
);
273 cacheDigestDestroy(cache
->digest
);
278 /* re-digests currently hashed entries */
280 cacheResetDigest(Cache
* cache
)
282 CacheEntry
*e
= NULL
;
285 struct timeval t_start
, t_end
;
288 fprintf(stderr
, "%s: init-ing digest with %d entries\n", cache
->name
, cache
->count
);
291 cacheDigestDestroy(cache
->digest
);
295 cache
->digest
= cacheDigestCreate(cache
->count
+ 1, 6);
300 gettimeofday(&t_start
, NULL
);
304 while ((e
= (CacheEntry
*)hash_next(hash
))) {
305 cacheDigestAdd(cache
->digest
, e
->key
);
308 gettimeofday(&t_end
, NULL
);
309 assert(cache
->digest
->count
== cache
->count
);
310 fprintf(stderr
, "%s: init-ed digest with %d entries\n",
311 cache
->name
, cache
->digest
->count
);
312 fprintf(stderr
, "%s: init took: %f sec, %f sec/M\n",
314 tvSubDsec(t_start
, t_end
),
315 (double) 1e6
* tvSubDsec(t_start
, t_end
) / cache
->count
);
316 /* check how long it takes to traverse the hash */
317 gettimeofday(&t_start
, NULL
);
320 for (e
= (CacheEntry
*)hash_next(hash
); e
; e
= (CacheEntry
*)hash_next(hash
)) {}
322 gettimeofday(&t_end
, NULL
);
323 fprintf(stderr
, "%s: hash scan took: %f sec, %f sec/M\n",
325 tvSubDsec(t_start
, t_end
),
326 (double) 1e6
* tvSubDsec(t_start
, t_end
) / cache
->count
);
330 cacheQueryPeer(Cache
* cache
, const cache_key
* key
)
332 const int peer_has_it
= hash_lookup(cache
->peer
->hash
, key
) != NULL
;
333 const int we_think_we_have_it
= cacheDigestTest(cache
->digest
, key
);
335 cache
->qstats
.query_count
++;
338 if (we_think_we_have_it
)
339 cache
->qstats
.true_hit_count
++;
341 cache
->qstats
.false_miss_count
++;
343 if (we_think_we_have_it
)
344 cache
->qstats
.false_hit_count
++;
346 cache
->qstats
.true_miss_count
++;
351 cacheQueryReport(Cache
* cache
, CacheQueryStats
* stats
)
353 fprintf(stdout
, "%s: peer queries: %d (%d%%)\n",
355 stats
->query_count
, xpercentInt(stats
->query_count
, cache
->req_count
)
357 fprintf(stdout
, "%s: t-hit: %d (%d%%) t-miss: %d (%d%%) t-*: %d (%d%%)\n",
359 stats
->true_hit_count
, xpercentInt(stats
->true_hit_count
, stats
->query_count
),
360 stats
->true_miss_count
, xpercentInt(stats
->true_miss_count
, stats
->query_count
),
361 stats
->true_hit_count
+ stats
->true_miss_count
,
362 xpercentInt(stats
->true_hit_count
+ stats
->true_miss_count
, stats
->query_count
)
364 fprintf(stdout
, "%s: f-hit: %d (%d%%) f-miss: %d (%d%%) f-*: %d (%d%%)\n",
366 stats
->false_hit_count
, xpercentInt(stats
->false_hit_count
, stats
->query_count
),
367 stats
->false_miss_count
, xpercentInt(stats
->false_miss_count
, stats
->query_count
),
368 stats
->false_hit_count
+ stats
->false_miss_count
,
369 xpercentInt(stats
->false_hit_count
+ stats
->false_miss_count
, stats
->query_count
)
374 cacheReport(Cache
* cache
)
376 fprintf(stdout
, "%s: entries: %d reqs: %d bad-add: %d bad-del: %d\n",
377 cache
->name
, cache
->count
, cache
->req_count
,
378 cache
->bad_add_count
, cache
->bad_del_count
);
383 cacheFetch(Cache
* cache
, const RawAccessLogEntry
* e
)
389 cacheQueryPeer(cache
, e
->key
);
393 swapStateReader(FileIterator
* fi
)
395 storeSwapLogData
*entry
;
398 fi
->entry
= xcalloc(1, sizeof(storeSwapLogData
));
400 entry
= (storeSwapLogData
*)fi
->entry
;
402 if (fread(entry
, sizeof(*entry
), 1, fi
->file
) != 1)
405 fi
->inner_time
= entry
->lastref
;
407 if (entry
->op
!= SWAP_LOG_ADD
&& entry
->op
!= SWAP_LOG_DEL
) {
408 fprintf(stderr
, "%s:%d: unknown swap log action\n", fi
->fname
, fi
->line_count
);
416 accessLogReader(FileIterator
* fi
)
418 static char buf
[4096];
419 RawAccessLogEntry
*entry
;
422 HttpRequestMethod method_id
= METHOD_NONE
;
428 fi
->entry
= xcalloc(1, sizeof(RawAccessLogEntry
));
430 memset(fi
->entry
, 0, sizeof(RawAccessLogEntry
));
432 entry
= (RawAccessLogEntry
*)fi
->entry
;
434 if (!fgets(buf
, sizeof(buf
), fi
->file
))
435 return frEof
; /* eof */
437 entry
->timestamp
= fi
->inner_time
= (time_t) atoi(buf
);
439 url
= strstr(buf
, "://");
441 hier
= url
? strstr(url
, " - ") : NULL
;
444 /*fprintf(stderr, "%s:%d: strange access log entry '%s'\n",
445 * fname, scanned_count, buf); */
451 while (!xisdigit(*method
)) {
459 method_id
= methodStrToId(method
);
461 if (method_id
== METHOD_NONE
) {
462 /*fprintf(stderr, "%s:%d: invalid method %s in '%s'\n",
463 * fname, scanned_count, method, buf); */
476 *strchr(hier
, '/') = '\0';
478 /*fprintf(stdout, "%s:%d: %s %s %s\n",
479 * fname, count, method, url, hier); */
480 entry
->use_icp
= strcmp(hier
, "NONE");
482 /* no ICP lookup for these status codes */
483 /* strcmp(hier, "NONE") &&
484 * strcmp(hier, "DIRECT") &&
485 * strcmp(hier, "FIREWALL_IP_DIRECT") &&
486 * strcmp(hier, "LOCAL_IP_DIRECT") &&
487 * strcmp(hier, "NO_DIRECT_FAIL") &&
488 * strcmp(hier, "NO_PARENT_DIRECT") &&
489 * strcmp(hier, "SINGLE_PARENT") &&
490 * strcmp(hier, "PASSTHROUGH_PARENT") &&
491 * strcmp(hier, "SSL_PARENT_MISS") &&
492 * strcmp(hier, "DEFAULT_PARENT");
494 xmemcpy(entry
->key
, storeKeyPublic(url
, method_id
), sizeof(entry
->key
));
496 /*fprintf(stdout, "%s:%d: %s %s %s %s\n",
497 * fname, count, method, storeKeyText(entry->key), url, hier); */
503 cachePurge(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
505 CacheEntry
*olde
= (CacheEntry
*) hash_lookup(cache
->hash
, s
->key
);
508 cache
->bad_del_count
++;
510 assert(cache
->count
);
511 hash_remove_link(cache
->hash
, (hash_link
*) olde
);
514 cacheDigestDel(cache
->digest
, s
->key
);
516 cacheEntryDestroy(olde
);
523 cacheStore(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
525 CacheEntry
*olde
= (CacheEntry
*) hash_lookup(cache
->hash
, s
->key
);
528 cache
->bad_add_count
++;
530 CacheEntry
*e
= cacheEntryCreate(s
);
531 hash_join(cache
->hash
, (hash_link
*)&e
->key
);
535 cacheDigestAdd(cache
->digest
, e
->key
);
540 cacheUpdateStore(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
545 cacheStore(cache
, s
, update_digest
);
549 cachePurge(cache
, s
, update_digest
);
558 usage(const char *prg_name
)
560 fprintf(stderr
, "usage: %s <access_log> <swap_state> ...\n",
566 main(int argc
, char *argv
[])
568 FileIterator
**fis
= NULL
;
569 const int fi_count
= argc
- 1;
570 int active_fi_count
= 0;
576 return usage(argv
[0]);
578 them
= cacheCreate("them");
580 us
= cacheCreate("us");
586 fis
= (FileIterator
**)xcalloc(fi_count
, sizeof(FileIterator
*));
588 /* init iterators with files */
589 fis
[0] = fileIteratorCreate(argv
[1], accessLogReader
);
591 for (i
= 2; i
< argc
; ++i
)
592 fis
[i
- 1] = fileIteratorCreate(argv
[i
], swapStateReader
);
594 /* check that all files were found */
595 for (i
= 0; i
< fi_count
; ++i
)
599 /* read prefix to get start-up contents of the peer cache */
602 for (i
= 1; i
< fi_count
; ++i
) {
603 FileIterator
*fi
= fis
[i
];
605 while (fi
->inner_time
> 0) {
606 if (((storeSwapLogData
*) fi
->entry
)->op
== SWAP_LOG_DEL
) {
607 cachePurge(them
, (storeSwapLogData
*)fi
->entry
, 0);
610 ready_time
= fi
->inner_time
;
612 if (ready_time
> 0 && fi
->inner_time
> ready_time
)
615 cacheStore(them
, (storeSwapLogData
*)fi
->entry
, 0);
618 fileIteratorAdvance(fi
);
622 /* digest peer cache content */
623 cacheResetDigest(them
);
625 us
->digest
= cacheDigestClone(them
->digest
); /* @netw@ */
627 /* shift the time in access log to match ready_time */
628 fileIteratorSetCurTime(fis
[0], ready_time
);
630 /* iterate, use the iterator with the smallest positive inner_time */
635 time_t next_time
= -1;
638 for (i
= 0; i
< fi_count
; ++i
) {
639 if (fis
[i
]->inner_time
>= 0) {
640 if (!active_fi_count
|| fis
[i
]->inner_time
< next_time
) {
642 next_time
= fis
[i
]->inner_time
;
650 cur_time
= next_time
;
651 /*fprintf(stderr, "%2d time: %d %s", next_i, (int)cur_time, ctime(&cur_time)); */
654 cacheFetch(us
, (RawAccessLogEntry
*)fis
[next_i
]->entry
);
656 cacheUpdateStore(them
, (storeSwapLogData
*)fis
[next_i
]->entry
, 1);
658 fileIteratorAdvance(fis
[next_i
]);
660 } while (active_fi_count
);
667 cacheQueryReport(us
, &us
->qstats
);
670 for (i
= 0; i
< argc
- 1; ++i
) {
671 fileIteratorDestroy(fis
[i
]);