2 * Copyright (C) 1996-2021 The Squid Software Foundation and contributors
4 * Squid software is distributed under GPLv2+ license and includes
5 * contributions from numerous individuals and organizations.
6 * Please see the COPYING and CONTRIBUTORS files for details.
10 * Test-suite for playing with cache digests
14 #include "CacheDigest.h"
15 #include "store_key_md5.h"
27 typedef struct _Cache Cache
;
34 CacheQueryStats qstats
;
35 int count
; /* #currently cached entries */
36 int req_count
; /* #requests to this cache */
37 int bad_add_count
; /* #duplicate adds */
38 int bad_del_count
; /* #dels with no prior add */
41 typedef struct _CacheEntry
{
44 struct _CacheEntry
*next
;
45 unsigned char key_arr
[SQUID_MD5_DIGEST_LENGTH
];
46 /* storeSwapLogData s; */
49 /* parsed access log entry */
52 cache_key key
[SQUID_MD5_DIGEST_LENGTH
];
54 short int use_icp
; /* true/false */
58 frError
= -2, frMore
= -1, frEof
= 0, frOk
= 1
61 typedef struct _FileIterator FileIterator
;
62 typedef fr_result(*FI_READER
) (FileIterator
* fi
);
64 struct _FileIterator
{
67 time_t inner_time
; /* timestamp of the current entry */
68 time_t time_offset
; /* to adjust time set by reader */
69 int line_count
; /* number of lines scanned */
70 int bad_line_count
; /* number of parsing errors */
71 int time_warp_count
; /* number of out-of-order entries in the file */
72 FI_READER reader
; /* reads next entry and updates inner_time */
73 void *entry
; /* buffer for the current entry, freed with xfree() */
77 static time_t cur_time
= -1; /* timestamp of the current log entry */
79 /* copied from url.c */
80 static HttpRequestMethod
81 methodStrToId(const char *s
)
83 if (strcasecmp(s
, "GET") == 0) {
85 } else if (strcasecmp(s
, "POST") == 0) {
87 } else if (strcasecmp(s
, "PUT") == 0) {
89 } else if (strcasecmp(s
, "HEAD") == 0) {
91 } else if (strcasecmp(s
, "CONNECT") == 0) {
92 return METHOD_CONNECT
;
93 } else if (strcasecmp(s
, "TRACE") == 0) {
95 } else if (strcasecmp(s
, "PURGE") == 0) {
104 static void fileIteratorAdvance(FileIterator
* fi
);
106 static FileIterator
*
107 fileIteratorCreate(const char *fname
, FI_READER reader
)
109 FileIterator
*fi
= (FileIterator
*)xcalloc(1, sizeof(FileIterator
));
110 assert(fname
&& reader
);
113 fi
->file
= fopen(fname
, "r");
116 fprintf(stderr
, "cannot open %s: %s\n", fname
, strerror(errno
));
119 fprintf(stderr
, "opened %s\n", fname
);
121 fileIteratorAdvance(fi
);
127 fileIteratorDestroy(FileIterator
* fi
)
133 fprintf(stderr
, "closed %s\n", fi
->fname
);
141 fileIteratorSetCurTime(FileIterator
* fi
, time_t ct
)
144 assert(fi
->inner_time
> 0);
145 fi
->time_offset
= ct
- fi
->inner_time
;
149 fileIteratorAdvance(FileIterator
* fi
)
155 const time_t last_time
= fi
->inner_time
;
157 res
= fi
->reader(fi
);
160 if (fi
->inner_time
< 0)
161 fi
->inner_time
= last_time
;
163 fi
->inner_time
+= fi
->time_offset
;
166 ++ fi
->bad_line_count
;
167 else if (res
== frEof
) {
168 fprintf(stderr
, "exhausted %s (%d entries) at %s",
169 fi
->fname
, fi
->line_count
, ctime(&fi
->inner_time
));
171 } else if (fi
->inner_time
< last_time
) {
172 assert(last_time
>= 0);
173 ++ fi
->time_warp_count
;
174 fi
->inner_time
= last_time
;
177 /* report progress */
178 if (!(fi
->line_count
% 50000))
179 fprintf(stderr
, "%s scanned %d K entries (%d bad) at %s",
180 fi
->fname
, fi
->line_count
/ 1000, fi
->bad_line_count
,
181 ctime(&fi
->inner_time
));
188 cacheEntryCreate(const storeSwapLogData
* s
)
190 CacheEntry
*e
= (CacheEntry
*)xcalloc(1, sizeof(CacheEntry
));
193 memcpy(e
->key_arr
, s
->key
, SQUID_MD5_DIGEST_LENGTH
);
194 e
->key
= &e
->key_arr
[0];
199 cacheEntryDestroy(CacheEntry
* e
)
208 cacheCreate(const char *name
)
211 assert(name
&& strlen(name
));
212 c
= (Cache
*)xcalloc(1, sizeof(Cache
));
214 c
->hash
= hash_create(storeKeyHashCmp
, (int)2e6
, storeKeyHashHash
);
219 cacheDestroy(Cache
* cache
)
221 CacheEntry
*e
= NULL
;
225 /* destroy hash table contents */
228 while ((e
= (CacheEntry
*)hash_next(hash
))) {
229 hash_remove_link(hash
, (hash_link
*) e
);
230 cacheEntryDestroy(e
);
233 /* destroy the hash table itself */
234 hashFreeMemory(hash
);
236 delete cache
->digest
;
240 /* re-digests currently hashed entries */
242 cacheResetDigest(Cache
* cache
)
244 CacheEntry
*e
= NULL
;
247 struct timeval t_start
, t_end
;
250 fprintf(stderr
, "%s: init-ing digest with %d entries\n", cache
->name
, cache
->count
);
254 delete cache
->digest
;
255 cache
->digest
= new CacheDigest(cache
->count
+ 1, 6);
260 gettimeofday(&t_start
, NULL
);
264 while ((e
= (CacheEntry
*)hash_next(hash
))) {
265 cache
->digest
->add(e
->key
);
268 gettimeofday(&t_end
, NULL
);
269 assert(cache
->digest
->count
== cache
->count
);
270 fprintf(stderr
, "%s: init-ed digest with %d entries\n",
271 cache
->name
, cache
->digest
->count
);
272 fprintf(stderr
, "%s: init took: %f sec, %f sec/M\n",
274 tvSubDsec(t_start
, t_end
),
275 (double) 1e6
* tvSubDsec(t_start
, t_end
) / cache
->count
);
276 /* check how long it takes to traverse the hash */
277 gettimeofday(&t_start
, NULL
);
280 for (e
= (CacheEntry
*)hash_next(hash
); e
; e
= (CacheEntry
*)hash_next(hash
)) {}
282 gettimeofday(&t_end
, NULL
);
283 fprintf(stderr
, "%s: hash scan took: %f sec, %f sec/M\n",
285 tvSubDsec(t_start
, t_end
),
286 (double) 1e6
* tvSubDsec(t_start
, t_end
) / cache
->count
);
290 cacheQueryPeer(Cache
* cache
, const cache_key
* key
)
292 const int peer_has_it
= hash_lookup(cache
->peer
->hash
, key
) != NULL
;
293 const int we_think_we_have_it
= cache
->digest
->test(key
);
295 ++ cache
->qstats
.query_count
;
298 if (we_think_we_have_it
)
299 ++ cache
->qstats
.true_hit_count
;
301 ++ cache
->qstats
.false_miss_count
;
303 if (we_think_we_have_it
)
304 ++ cache
->qstats
.false_hit_count
;
306 ++ cache
->qstats
.true_miss_count
;
311 cacheQueryReport(Cache
* cache
, CacheQueryStats
* stats
)
313 fprintf(stdout
, "%s: peer queries: %d (%d%%)\n",
315 stats
->query_count
, xpercentInt(stats
->query_count
, cache
->req_count
)
317 fprintf(stdout
, "%s: t-hit: %d (%d%%) t-miss: %d (%d%%) t-*: %d (%d%%)\n",
319 stats
->true_hit_count
, xpercentInt(stats
->true_hit_count
, stats
->query_count
),
320 stats
->true_miss_count
, xpercentInt(stats
->true_miss_count
, stats
->query_count
),
321 stats
->true_hit_count
+ stats
->true_miss_count
,
322 xpercentInt(stats
->true_hit_count
+ stats
->true_miss_count
, stats
->query_count
)
324 fprintf(stdout
, "%s: f-hit: %d (%d%%) f-miss: %d (%d%%) f-*: %d (%d%%)\n",
326 stats
->false_hit_count
, xpercentInt(stats
->false_hit_count
, stats
->query_count
),
327 stats
->false_miss_count
, xpercentInt(stats
->false_miss_count
, stats
->query_count
),
328 stats
->false_hit_count
+ stats
->false_miss_count
,
329 xpercentInt(stats
->false_hit_count
+ stats
->false_miss_count
, stats
->query_count
)
334 cacheReport(Cache
* cache
)
336 fprintf(stdout
, "%s: entries: %d reqs: %d bad-add: %d bad-del: %d\n",
337 cache
->name
, cache
->count
, cache
->req_count
,
338 cache
->bad_add_count
, cache
->bad_del_count
);
343 cacheFetch(Cache
* cache
, const RawAccessLogEntry
* e
)
349 cacheQueryPeer(cache
, e
->key
);
353 swapStateReader(FileIterator
* fi
)
355 storeSwapLogData
*entry
;
358 fi
->entry
= xcalloc(1, sizeof(storeSwapLogData
));
360 entry
= (storeSwapLogData
*)fi
->entry
;
362 if (fread(entry
, sizeof(*entry
), 1, fi
->file
) != 1)
365 fi
->inner_time
= entry
->lastref
;
367 if (entry
->op
!= SWAP_LOG_ADD
&& entry
->op
!= SWAP_LOG_DEL
) {
368 fprintf(stderr
, "%s:%d: unknown swap log action\n", fi
->fname
, fi
->line_count
);
376 accessLogReader(FileIterator
* fi
)
378 static char buf
[4096];
379 RawAccessLogEntry
*entry
;
382 HttpRequestMethod method_id
= METHOD_NONE
;
388 fi
->entry
= xcalloc(1, sizeof(RawAccessLogEntry
));
390 memset(fi
->entry
, 0, sizeof(RawAccessLogEntry
));
392 entry
= (RawAccessLogEntry
*)fi
->entry
;
394 if (!fgets(buf
, sizeof(buf
), fi
->file
))
395 return frEof
; /* eof */
397 entry
->timestamp
= fi
->inner_time
= (time_t) atoi(buf
);
399 url
= strstr(buf
, "://");
401 hier
= url
? strstr(url
, " - ") : NULL
;
404 /*fprintf(stderr, "%s:%d: strange access log entry '%s'\n",
405 * fname, scanned_count, buf); */
411 while (!xisdigit(*method
)) {
419 method_id
= methodStrToId(method
);
421 if (method_id
== METHOD_NONE
) {
422 /*fprintf(stderr, "%s:%d: invalid method %s in '%s'\n",
423 * fname, scanned_count, method, buf); */
436 *strchr(hier
, '/') = '\0';
438 /*fprintf(stdout, "%s:%d: %s %s %s\n",
439 * fname, count, method, url, hier); */
440 entry
->use_icp
= strcmp(hier
, "NONE");
442 /* no ICP lookup for these status codes */
443 /* strcmp(hier, "NONE") &&
444 * strcmp(hier, "DIRECT") &&
445 * strcmp(hier, "FIREWALL_IP_DIRECT") &&
446 * strcmp(hier, "LOCAL_IP_DIRECT") &&
447 * strcmp(hier, "NO_DIRECT_FAIL") &&
448 * strcmp(hier, "NO_PARENT_DIRECT") &&
449 * strcmp(hier, "SINGLE_PARENT") &&
450 * strcmp(hier, "PASSTHROUGH_PARENT") &&
451 * strcmp(hier, "SSL_PARENT_MISS") &&
452 * strcmp(hier, "DEFAULT_PARENT");
454 memcpy(entry
->key
, storeKeyPublic(url
, method_id
), sizeof(entry
->key
));
456 /*fprintf(stdout, "%s:%d: %s %s %s %s\n",
457 * fname, count, method, storeKeyText(entry->key), url, hier); */
462 cachePurge(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
464 CacheEntry
*olde
= (CacheEntry
*) hash_lookup(cache
->hash
, s
->key
);
467 ++ cache
->bad_del_count
;
469 assert(cache
->count
);
470 hash_remove_link(cache
->hash
, (hash_link
*) olde
);
473 cache
->digest
->remove(s
->key
);
475 cacheEntryDestroy(olde
);
482 cacheStore(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
484 CacheEntry
*olde
= (CacheEntry
*) hash_lookup(cache
->hash
, s
->key
);
487 ++ cache
->bad_add_count
;
489 CacheEntry
*e
= cacheEntryCreate(s
);
490 hash_join(cache
->hash
, (hash_link
*)&e
->key
);
494 cache
->digest
->add(e
->key
);
499 cacheUpdateStore(Cache
* cache
, storeSwapLogData
* s
, int update_digest
)
504 cacheStore(cache
, s
, update_digest
);
508 cachePurge(cache
, s
, update_digest
);
517 usage(const char *prg_name
)
519 fprintf(stderr
, "usage: %s <access_log> <swap_state> ...\n",
525 main(int argc
, char *argv
[])
527 FileIterator
**fis
= NULL
;
528 const int fi_count
= argc
- 1;
529 int active_fi_count
= 0;
535 return usage(argv
[0]);
537 them
= cacheCreate("them");
539 us
= cacheCreate("us");
545 fis
= (FileIterator
**)xcalloc(fi_count
, sizeof(FileIterator
*));
547 /* init iterators with files */
548 fis
[0] = fileIteratorCreate(argv
[1], accessLogReader
);
550 for (i
= 2; i
< argc
; ++i
)
551 fis
[i
- 1] = fileIteratorCreate(argv
[i
], swapStateReader
);
553 /* check that all files were found */
554 for (i
= 0; i
< fi_count
; ++i
)
558 /* read prefix to get start-up contents of the peer cache */
561 for (i
= 1; i
< fi_count
; ++i
) {
562 FileIterator
*fi
= fis
[i
];
564 while (fi
->inner_time
> 0) {
565 if (((storeSwapLogData
*) fi
->entry
)->op
== SWAP_LOG_DEL
) {
566 cachePurge(them
, (storeSwapLogData
*)fi
->entry
, 0);
569 ready_time
= fi
->inner_time
;
571 if (ready_time
> 0 && fi
->inner_time
> ready_time
)
574 cacheStore(them
, (storeSwapLogData
*)fi
->entry
, 0);
577 fileIteratorAdvance(fi
);
581 /* digest peer cache content */
582 cacheResetDigest(them
);
584 us
->digest
= them
->digest
->clone();
586 /* shift the time in access log to match ready_time */
587 fileIteratorSetCurTime(fis
[0], ready_time
);
589 /* iterate, use the iterator with the smallest positive inner_time */
594 time_t next_time
= -1;
597 for (i
= 0; i
< fi_count
; ++i
) {
598 if (fis
[i
]->inner_time
>= 0) {
599 if (!active_fi_count
|| fis
[i
]->inner_time
< next_time
) {
601 next_time
= fis
[i
]->inner_time
;
609 cur_time
= next_time
;
610 /*fprintf(stderr, "%2d time: %d %s", next_i, (int)cur_time, ctime(&cur_time)); */
613 cacheFetch(us
, (RawAccessLogEntry
*)fis
[next_i
]->entry
);
615 cacheUpdateStore(them
, (storeSwapLogData
*)fis
[next_i
]->entry
, 1);
617 fileIteratorAdvance(fis
[next_i
]);
619 } while (active_fi_count
);
626 cacheQueryReport(us
, &us
->qstats
);
629 for (i
= 0; i
< argc
- 1; ++i
) {
630 fileIteratorDestroy(fis
[i
]);