test_cache_digest.cc
Go to the documentation of this file.
1 /*
2  * Copyright (C) 1996-2018 The Squid Software Foundation and contributors
3  *
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.
7  */
8 
9 /*
10  * Test-suite for playing with cache digests
11  */
12 
13 #include "squid.h"
14 #include "CacheDigest.h"
15 #include "store_key_md5.h"
16 
17 #include <cerrno>
18 
19 typedef struct {
26 
27 typedef struct _Cache Cache;
28 
29 struct _Cache {
30  const char *name;
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 */
39 };
40 
41 typedef struct _CacheEntry {
42  const cache_key *key;
43 
44  struct _CacheEntry *next;
45  unsigned char key_arr[SQUID_MD5_DIGEST_LENGTH];
46  /* storeSwapLogData s; */
47 } CacheEntry;
48 
49 /* parsed access log entry */
50 
51 typedef struct {
53  time_t timestamp;
54  short int use_icp; /* true/false */
56 
57 typedef enum {
58  frError = -2, frMore = -1, frEof = 0, frOk = 1
59 } fr_result;
60 
61 typedef struct _FileIterator FileIterator;
62 typedef fr_result(*FI_READER) (FileIterator * fi);
63 
64 struct _FileIterator {
65  const char *fname;
66  FILE *file;
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() */
74 };
75 
76 /* globals */
77 static time_t cur_time = -1; /* timestamp of the current log entry */
78 
79 /* copied from url.c */
80 static HttpRequestMethod
81 methodStrToId(const char *s)
82 {
83  if (strcasecmp(s, "GET") == 0) {
84  return METHOD_GET;
85  } else if (strcasecmp(s, "POST") == 0) {
86  return METHOD_POST;
87  } else if (strcasecmp(s, "PUT") == 0) {
88  return METHOD_PUT;
89  } else if (strcasecmp(s, "HEAD") == 0) {
90  return METHOD_HEAD;
91  } else if (strcasecmp(s, "CONNECT") == 0) {
92  return METHOD_CONNECT;
93  } else if (strcasecmp(s, "TRACE") == 0) {
94  return METHOD_TRACE;
95  } else if (strcasecmp(s, "PURGE") == 0) {
96  return METHOD_PURGE;
97  }
98 
99  return METHOD_NONE;
100 }
101 
102 /* FileIterator */
103 
104 static void fileIteratorAdvance(FileIterator * fi);
105 
106 static FileIterator *
107 fileIteratorCreate(const char *fname, FI_READER reader)
108 {
109  FileIterator *fi = (FileIterator *)xcalloc(1, sizeof(FileIterator));
110  assert(fname && reader);
111  fi->fname = fname;
112  fi->reader = reader;
113  fi->file = fopen(fname, "r");
114 
115  if (!fi->file) {
116  fprintf(stderr, "cannot open %s: %s\n", fname, strerror(errno));
117  return NULL;
118  } else
119  fprintf(stderr, "opened %s\n", fname);
120 
122 
123  return fi;
124 }
125 
126 static void
128 {
129  assert(fi);
130 
131  if (fi->file) {
132  fclose(fi->file);
133  fprintf(stderr, "closed %s\n", fi->fname);
134  }
135 
136  xfree(fi->entry);
137  xfree(fi);
138 }
139 
140 static void
142 {
143  assert(fi);
144  assert(fi->inner_time > 0);
145  fi->time_offset = ct - fi->inner_time;
146 }
147 
148 static void
150 {
151  int res;
152  assert(fi);
153 
154  do {
155  const time_t last_time = fi->inner_time;
156  fi->inner_time = -1;
157  res = fi->reader(fi);
158  ++ fi->line_count;
159 
160  if (fi->inner_time < 0)
161  fi->inner_time = last_time;
162  else
163  fi->inner_time += fi->time_offset;
164 
165  if (res == frError)
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));
170  fi->inner_time = -1;
171  } else if (fi->inner_time < last_time) {
172  assert(last_time >= 0);
173  ++ fi->time_warp_count;
174  fi->inner_time = last_time;
175  }
176 
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));
182  } while (res < 0);
183 }
184 
185 /* CacheEntry */
186 
187 static CacheEntry *
188 cacheEntryCreate(const storeSwapLogData * s)
189 {
190  CacheEntry *e = (CacheEntry *)xcalloc(1, sizeof(CacheEntry));
191  assert(s);
192  /* e->s = *s; */
193  memcpy(e->key_arr, s->key, SQUID_MD5_DIGEST_LENGTH);
194  e->key = &e->key_arr[0];
195  return e;
196 }
197 
198 static void
200 {
201  assert(e);
202  xfree(e);
203 }
204 
205 /* Cache */
206 
207 static Cache *
208 cacheCreate(const char *name)
209 {
210  Cache *c;
211  assert(name && strlen(name));
212  c = (Cache *)xcalloc(1, sizeof(Cache));
213  c->name = name;
215  return c;
216 }
217 
218 static void
220 {
221  CacheEntry *e = NULL;
222  hash_table *hash;
223  assert(cache);
224  hash = cache->hash;
225  /* destroy hash table contents */
226  hash_first(hash);
227 
228  while ((e = (CacheEntry *)hash_next(hash))) {
229  hash_remove_link(hash, (hash_link *) e);
231  }
232 
233  /* destroy the hash table itself */
234  hashFreeMemory(hash);
235 
236  delete cache->digest;
237  xfree(cache);
238 }
239 
240 /* re-digests currently hashed entries */
241 static void
243 {
244  CacheEntry *e = NULL;
245  hash_table *hash;
246 
247  struct timeval t_start, t_end;
248 
249  assert(cache);
250  fprintf(stderr, "%s: init-ing digest with %d entries\n", cache->name, cache->count);
251 
252  hash = cache->hash;
253 
254  delete cache->digest;
255  cache->digest = new CacheDigest(cache->count + 1, 6);
256 
257  if (!cache->count)
258  return;
259 
260  gettimeofday(&t_start, NULL);
261 
262  hash_first(hash);
263 
264  while ((e = (CacheEntry *)hash_next(hash))) {
265  cache->digest->add(e->key);
266  }
267 
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",
273  cache->name,
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);
278  hash_first(hash);
279 
280  for (e = (CacheEntry *)hash_next(hash); e; e = (CacheEntry *)hash_next(hash)) {}
281 
282  gettimeofday(&t_end, NULL);
283  fprintf(stderr, "%s: hash scan took: %f sec, %f sec/M\n",
284  cache->name,
285  tvSubDsec(t_start, t_end),
286  (double) 1e6 * tvSubDsec(t_start, t_end) / cache->count);
287 }
288 
289 static void
290 cacheQueryPeer(Cache * cache, const cache_key * key)
291 {
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);
294 
295  ++ cache->qstats.query_count;
296 
297  if (peer_has_it) {
298  if (we_think_we_have_it)
299  ++ cache->qstats.true_hit_count;
300  else
301  ++ cache->qstats.false_miss_count;
302  } else {
303  if (we_think_we_have_it)
304  ++ cache->qstats.false_hit_count;
305  else
306  ++ cache->qstats.true_miss_count;
307  }
308 }
309 
310 static void
312 {
313  fprintf(stdout, "%s: peer queries: %d (%d%%)\n",
314  cache->name,
315  stats->query_count, xpercentInt(stats->query_count, cache->req_count)
316  );
317  fprintf(stdout, "%s: t-hit: %d (%d%%) t-miss: %d (%d%%) t-*: %d (%d%%)\n",
318  cache->name,
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)
323  );
324  fprintf(stdout, "%s: f-hit: %d (%d%%) f-miss: %d (%d%%) f-*: %d (%d%%)\n",
325  cache->name,
326  stats->false_hit_count, xpercentInt(stats->false_hit_count, stats->query_count),
328  stats->false_hit_count + stats->false_miss_count,
330  );
331 }
332 
333 static void
335 {
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);
339 
340 }
341 
342 static void
343 cacheFetch(Cache * cache, const RawAccessLogEntry * e)
344 {
345  assert(e);
346  ++ cache->req_count;
347 
348  if (e->use_icp)
349  cacheQueryPeer(cache, e->key);
350 }
351 
352 static fr_result
354 {
355  storeSwapLogData *entry;
356 
357  if (!fi->entry)
358  fi->entry = xcalloc(1, sizeof(storeSwapLogData));
359 
360  entry = (storeSwapLogData *)fi->entry;
361 
362  if (fread(entry, sizeof(*entry), 1, fi->file) != 1)
363  return frEof;
364 
365  fi->inner_time = entry->lastref;
366 
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);
369  exit(-3);
370  }
371 
372  return frOk;
373 }
374 
375 static fr_result
377 {
378  static char buf[4096];
379  RawAccessLogEntry *entry;
380  char *url;
381  char *method;
382  HttpRequestMethod method_id = METHOD_NONE;
383  char *hier = NULL;
384 
385  assert(fi);
386 
387  if (!fi->entry)
388  fi->entry = xcalloc(1, sizeof(RawAccessLogEntry));
389  else
390  memset(fi->entry, 0, sizeof(RawAccessLogEntry));
391 
392  entry = (RawAccessLogEntry*)fi->entry;
393 
394  if (!fgets(buf, sizeof(buf), fi->file))
395  return frEof; /* eof */
396 
397  entry->timestamp = fi->inner_time = (time_t) atoi(buf);
398 
399  url = strstr(buf, "://");
400 
401  hier = url ? strstr(url, " - ") : NULL;
402 
403  if (!url || !hier) {
404  /*fprintf(stderr, "%s:%d: strange access log entry '%s'\n",
405  * fname, scanned_count, buf); */
406  return frError;
407  }
408 
409  method = url;
410 
411  while (!xisdigit(*method)) {
412  if (*method == ' ')
413  *method = '\0';
414 
415  --method;
416  }
417 
418  method += 2;
419  method_id = methodStrToId(method);
420 
421  if (method_id == METHOD_NONE) {
422  /*fprintf(stderr, "%s:%d: invalid method %s in '%s'\n",
423  * fname, scanned_count, method, buf); */
424  return frError;
425  }
426 
427  while (*url)
428  --url;
429 
430  ++url;
431 
432  *hier = '\0';
433 
434  hier += 3;
435 
436  *strchr(hier, '/') = '\0';
437 
438  /*fprintf(stdout, "%s:%d: %s %s %s\n",
439  * fname, count, method, url, hier); */
440  entry->use_icp = strcmp(hier, "NONE");
441 
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");
453  */
454  memcpy(entry->key, storeKeyPublic(url, method_id), sizeof(entry->key));
455 
456  /*fprintf(stdout, "%s:%d: %s %s %s %s\n",
457  * fname, count, method, storeKeyText(entry->key), url, hier); */
458  return frOk;
459 }
460 
461 static void
462 cachePurge(Cache * cache, storeSwapLogData * s, int update_digest)
463 {
464  CacheEntry *olde = (CacheEntry *) hash_lookup(cache->hash, s->key);
465 
466  if (!olde) {
467  ++ cache->bad_del_count;
468  } else {
469  assert(cache->count);
470  hash_remove_link(cache->hash, (hash_link *) olde);
471 
472  if (update_digest)
473  cache->digest->remove(s->key);
474 
475  cacheEntryDestroy(olde);
476 
477  -- cache->count;
478  }
479 }
480 
481 static void
482 cacheStore(Cache * cache, storeSwapLogData * s, int update_digest)
483 {
484  CacheEntry *olde = (CacheEntry *) hash_lookup(cache->hash, s->key);
485 
486  if (olde) {
487  ++ cache->bad_add_count;
488  } else {
490  hash_join(cache->hash, (hash_link *)&e->key);
491  ++ cache->count;
492 
493  if (update_digest)
494  cache->digest->add(e->key);
495  }
496 }
497 
498 static void
499 cacheUpdateStore(Cache * cache, storeSwapLogData * s, int update_digest)
500 {
501  switch (s->op) {
502 
503  case SWAP_LOG_ADD:
504  cacheStore(cache, s, update_digest);
505  break;
506 
507  case SWAP_LOG_DEL:
508  cachePurge(cache, s, update_digest);
509  break;
510 
511  default:
512  assert(0);
513  }
514 }
515 
516 static int
517 usage(const char *prg_name)
518 {
519  fprintf(stderr, "usage: %s <access_log> <swap_state> ...\n",
520  prg_name);
521  return EXIT_FAILURE;
522 }
523 
524 int
525 main(int argc, char *argv[])
526 {
527  FileIterator **fis = NULL;
528  const int fi_count = argc - 1;
529  int active_fi_count = 0;
530  time_t ready_time;
531  Cache *them, *us;
532  int i;
533 
534  if (argc < 3)
535  return usage(argv[0]);
536 
537  them = cacheCreate("them");
538 
539  us = cacheCreate("us");
540 
541  them->peer = us;
542 
543  us->peer = them;
544 
545  fis = (FileIterator **)xcalloc(fi_count, sizeof(FileIterator *));
546 
547  /* init iterators with files */
548  fis[0] = fileIteratorCreate(argv[1], accessLogReader);
549 
550  for (i = 2; i < argc; ++i)
551  fis[i - 1] = fileIteratorCreate(argv[i], swapStateReader);
552 
553  /* check that all files were found */
554  for (i = 0; i < fi_count; ++i)
555  if (!fis[i])
556  return -2;
557 
558  /* read prefix to get start-up contents of the peer cache */
559  ready_time = -1;
560 
561  for (i = 1; i < fi_count; ++i) {
562  FileIterator *fi = fis[i];
563 
564  while (fi->inner_time > 0) {
565  if (((storeSwapLogData *) fi->entry)->op == SWAP_LOG_DEL) {
566  cachePurge(them, (storeSwapLogData *)fi->entry, 0);
567 
568  if (ready_time < 0)
569  ready_time = fi->inner_time;
570  } else {
571  if (ready_time > 0 && fi->inner_time > ready_time)
572  break;
573 
574  cacheStore(them, (storeSwapLogData *)fi->entry, 0);
575  }
576 
578  }
579  }
580 
581  /* digest peer cache content */
582  cacheResetDigest(them);
583 
584  us->digest = them->digest->clone();
585 
586  /* shift the time in access log to match ready_time */
587  fileIteratorSetCurTime(fis[0], ready_time);
588 
589  /* iterate, use the iterator with the smallest positive inner_time */
590  cur_time = -1;
591 
592  do {
593  int next_i = -1;
594  time_t next_time = -1;
595  active_fi_count = 0;
596 
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) {
600  next_i = i;
601  next_time = fis[i]->inner_time;
602  }
603 
604  ++active_fi_count;
605  }
606  }
607 
608  if (next_i >= 0) {
609  cur_time = next_time;
610  /*fprintf(stderr, "%2d time: %d %s", next_i, (int)cur_time, ctime(&cur_time)); */
611 
612  if (next_i == 0)
613  cacheFetch(us, (RawAccessLogEntry *)fis[next_i]->entry);
614  else
615  cacheUpdateStore(them, (storeSwapLogData *)fis[next_i]->entry, 1);
616 
617  fileIteratorAdvance(fis[next_i]);
618  }
619  } while (active_fi_count);
620 
621  /* report */
622  cacheReport(them);
623 
624  cacheReport(us);
625 
626  cacheQueryReport(us, &us->qstats);
627 
628  /* clean */
629  for (i = 0; i < argc - 1; ++i) {
630  fileIteratorDestroy(fis[i]);
631  }
632 
633  xfree(fis);
634  cacheDestroy(them);
635  cacheDestroy(us);
636  return EXIT_SUCCESS;
637 }
638 
struct _CacheEntry * next
Definition: cache_diff.cc:30
#define assert(EX)
Definition: assert.h:17
SQUIDCEXTERN void hash_first(hash_table *)
Definition: hash.cc:176
char * strerror(int ern)
Definition: strerror.c:22
int main(int, char *[])
Definition: unitTestMain.h:25
const cache_key * key
Definition: cache_diff.cc:28
uint64_t count
Definition: CacheDigest.h:55
void usage()
Definition: find_password.c:40
SQUIDCEXTERN void hashFreeMemory(hash_table *)
Definition: hash.cc:272
unsigned char key_arr[SQUID_MD5_DIGEST_LENGTH]
Definition: cache_diff.cc:32
CacheDigest * digest
static void fileIteratorSetCurTime(FileIterator *fi, time_t ct)
static void cachePurge(Cache *cache, storeSwapLogData *s, int update_digest)
static CacheEntry * cacheEntryCreate(const storeSwapLogData *s)
unsigned char cache_key
Store key.
Definition: forward.h:29
#define xcalloc
Definition: membanger.c:57
int i
Definition: membanger.c:49
HASHHASH storeKeyHashHash
class Ping::pingStats_ stats
static void fileIteratorDestroy(FileIterator *fi)
SQUIDCEXTERN void hash_join(hash_table *, hash_link *)
Definition: hash.cc:132
hash_table * hash
static void cacheDestroy(Cache *cache)
const char * fname
static fr_result swapStateReader(FileIterator *fi)
SQUIDCEXTERN int xpercentInt(double part, double whole)
Definition: util.c:60
static void cacheFetch(Cache *cache, const RawAccessLogEntry *e)
void add(const cache_key *key)
Definition: CacheDigest.cc:107
#define SQUID_MD5_DIGEST_LENGTH
Definition: md5.h:66
static void cacheStore(Cache *cache, storeSwapLogData *s, int update_digest)
HASHCMP storeKeyHashCmp
static hash_table * hash
Definition: text_backend.cc:41
static Cache * cacheCreate(const char *name)
SQUIDCEXTERN hash_link * hash_lookup(hash_table *, const void *)
Definition: hash.cc:147
void remove(const cache_key *key)
Definition: CacheDigest.cc:151
static void cacheQueryReport(Cache *cache, CacheQueryStats *stats)
cache_key key[SQUID_MD5_DIGEST_LENGTH]
static void cacheReport(Cache *cache)
struct _CacheEntry CacheEntry
SQUIDCEXTERN hash_table * hash_create(HASHCMP *, int, HASHHASH *)
Definition: hash.cc:109
CacheQueryStats qstats
static fr_result accessLogReader(FileIterator *fi)
static void cacheQueryPeer(Cache *cache, const cache_key *key)
static HttpRequestMethod methodStrToId(const char *s)
CacheDigest * clone() const
produce a new identical copy of the digest object
Definition: CacheDigest.cc:68
fr_result(* FI_READER)(FileIterator *fi)
void const char * buf
Definition: stub_helper.cc:16
static time_t cur_time
SQUIDCEXTERN hash_link * hash_next(hash_table *)
Definition: hash.cc:192
static FileIterator * fileIteratorCreate(const char *fname, FI_READER reader)
#define xisdigit(x)
Definition: xis.h:20
static void cacheUpdateStore(Cache *cache, storeSwapLogData *s, int update_digest)
static void cacheResetDigest(Cache *cache)
size_t HttpReply *STUB StoreEntry const KeyScope scope const HttpRequestMethod & method
Definition: stub_store.cc:122
SQUIDCEXTERN void hash_remove_link(hash_table *, hash_link *)
Definition: hash.cc:224
static void fileIteratorAdvance(FileIterator *fi)
#define xfree
const cache_key * storeKeyPublic(const char *url, const HttpRequestMethod &method, const KeyScope keyScope)
#define NULL
Definition: types.h:166
Cache * peer
static void cacheEntryDestroy(CacheEntry *e)
const char * name
SQUIDCEXTERN double tvSubDsec(struct timeval, struct timeval)
Definition: util.c:46

 

Introduction

Documentation

Support

Miscellaneous

Web Site Translations

Mirrors