From fe55330a60e4e14ea6cac2ff40d50eddca4cf140 Mon Sep 17 00:00:00 2001 From: Rusty Russell Date: Wed, 1 Dec 2010 23:36:14 +1030 Subject: [PATCH] tdb2: Add stats attribute. This is good for deep debugging. --- ccan/tdb2/free.c | 17 ++++++++++- ccan/tdb2/hash.c | 1 + ccan/tdb2/io.c | 8 ++++- ccan/tdb2/lock.c | 8 ++++- ccan/tdb2/private.h | 9 ++++++ ccan/tdb2/tdb.c | 9 ++++++ ccan/tdb2/tdb2.h | 24 ++++++++++++++- ccan/tdb2/tools/speed.c | 67 ++++++++++++++++++++++++++++++++++++++++- ccan/tdb2/transaction.c | 1 + 9 files changed, 139 insertions(+), 5 deletions(-) diff --git a/ccan/tdb2/free.c b/ccan/tdb2/free.c index a854aadf..816d0ee5 100644 --- a/ccan/tdb2/free.c +++ b/ccan/tdb2/free.c @@ -262,6 +262,7 @@ static int coalesce(struct tdb_context *tdb, struct tdb_free_record pad, *r; tdb_off_t end; + add_stat(tdb, alloc_coalesce_tried, 1); end = off + sizeof(struct tdb_used_record) + data_len; while (end < tdb->map_size) { @@ -281,8 +282,10 @@ static int coalesce(struct tdb_context *tdb, nb_off = bucket_off(flist_offset(tdb, flist), bucket); /* We may be violating lock order here, so best effort. */ - if (tdb_lock_free_bucket(tdb, nb_off, TDB_LOCK_NOWAIT) == -1) + if (tdb_lock_free_bucket(tdb, nb_off, TDB_LOCK_NOWAIT) == -1) { + add_stat(tdb, alloc_coalesce_lockfail, 1); break; + } /* Now we have lock, re-check. */ r = tdb_get(tdb, end, &pad, sizeof(pad)); @@ -292,12 +295,14 @@ static int coalesce(struct tdb_context *tdb, } if (unlikely(frec_magic(r) != TDB_FREE_MAGIC)) { + add_stat(tdb, alloc_coalesce_race, 1); tdb_unlock_free_bucket(tdb, nb_off); break; } if (unlikely(frec_flist(r) != flist) || unlikely(size_to_bucket(frec_len(r)) != bucket)) { + add_stat(tdb, alloc_coalesce_race, 1); tdb_unlock_free_bucket(tdb, nb_off); break; } @@ -309,6 +314,7 @@ static int coalesce(struct tdb_context *tdb, end += sizeof(struct tdb_used_record) + frec_len(r); tdb_unlock_free_bucket(tdb, nb_off); + add_stat(tdb, alloc_coalesce_num_merged, 1); } /* Didn't find any adjacent free? */ @@ -343,6 +349,7 @@ static int coalesce(struct tdb_context *tdb, if (tdb_access_commit(tdb, r) != 0) goto err; + add_stat(tdb, alloc_coalesce_succeeded, 1); tdb_unlock_free_bucket(tdb, b_off); if (add_free_record(tdb, off, end - off) == -1) @@ -368,6 +375,7 @@ static tdb_off_t lock_and_alloc(struct tdb_context *tdb, double multiplier; size_t size = adjust_size(keylen, datalen); + add_stat(tdb, allocs, 1); again: b_off = bucket_off(flist_off, bucket); @@ -453,6 +461,7 @@ again: /* Bucket of leftover will be <= current bucket, so nested * locking is allowed. */ if (leftover) { + add_stat(tdb, alloc_leftover, 1); if (add_free_record(tdb, best_off + sizeof(rec) + frec_len(&best) - leftover, @@ -502,6 +511,10 @@ static tdb_off_t get_free(struct tdb_context *tdb, if (off == TDB_OFF_ERR) return TDB_OFF_ERR; if (off != 0) { + if (b == start_b) + add_stat(tdb, alloc_bucket_exact, 1); + if (b == TDB_FREE_BUCKETS - 1) + add_stat(tdb, alloc_bucket_max, 1); /* Worked? Stay using this list. */ tdb->flist_off = flist_off; tdb->flist = flist; @@ -513,6 +526,7 @@ static tdb_off_t get_free(struct tdb_context *tdb, /* Hmm, try next list. */ flist_off = next_flist(tdb, flist_off); flist++; + if (flist_off == 0) { wrapped = true; flist_off = first_flist(tdb); @@ -596,6 +610,7 @@ static int tdb_expand(struct tdb_context *tdb, tdb_len_t size) /* We need to drop this lock before adding free record. */ tdb_unlock_expand(tdb, F_WRLCK); + add_stat(tdb, expands, 1); return add_free_record(tdb, old_size, wanted); } diff --git a/ccan/tdb2/hash.c b/ccan/tdb2/hash.c index 51874918..7c7843ec 100644 --- a/ccan/tdb2/hash.c +++ b/ccan/tdb2/hash.c @@ -358,6 +358,7 @@ static int expand_group(struct tdb_context *tdb, struct hash_info *h) if (subhash == TDB_OFF_ERR) return -1; + add_stat(tdb, alloc_subhash, 1); if (zero_out(tdb, subhash + sizeof(struct tdb_used_record), sizeof(tdb_off_t) << TDB_SUBLEVEL_HASH_BITS) == -1) return -1; diff --git a/ccan/tdb2/io.c b/ccan/tdb2/io.c index 6c8f847b..e2649409 100644 --- a/ccan/tdb2/io.c +++ b/ccan/tdb2/io.c @@ -443,7 +443,7 @@ static int tdb_expand_file(struct tdb_context *tdb, tdb_len_t addition) file isn't sparse, which would be very bad if we ran out of disk. This must be done with write, not via mmap */ memset(buf, 0x43, sizeof(buf)); - if (fill(tdb, buf, sizeof(buf), tdb->map_size, addition) == -1) + if (0 || fill(tdb, buf, sizeof(buf), tdb->map_size, addition) == -1) return -1; tdb->map_size += addition; tdb_mmap(tdb); @@ -546,6 +546,12 @@ static void *tdb_direct(struct tdb_context *tdb, tdb_off_t off, size_t len) return (char *)tdb->map_ptr + off; } +void add_stat_(struct tdb_context *tdb, uint64_t *stat, size_t val) +{ + if ((uintptr_t)stat < (uintptr_t)tdb->stats + tdb->stats->size) + *stat += val; +} + static const struct tdb_methods io_methods = { tdb_read, tdb_write, diff --git a/ccan/tdb2/lock.c b/ccan/tdb2/lock.c index fe607243..65e9dc25 100644 --- a/ccan/tdb2/lock.c +++ b/ccan/tdb2/lock.c @@ -40,10 +40,13 @@ static int fcntl_lock(struct tdb_context *tdb, fl.l_len = len; fl.l_pid = 0; + add_stat(tdb, lock_lowlevel, 1); if (waitflag) return fcntl(tdb->fd, F_SETLKW, &fl); - else + else { + add_stat(tdb, lock_nonblock, 1); return fcntl(tdb->fd, F_SETLK, &fl); + } } static int fcntl_unlock(struct tdb_context *tdb, int rw, off_t off, off_t len) @@ -286,6 +289,8 @@ static int tdb_nest_lock(struct tdb_context *tdb, tdb_off_t offset, int ltype, if (tdb->flags & TDB_NOLOCK) return 0; + add_stat(tdb, locks, 1); + new_lck = find_nestlock(tdb, offset); if (new_lck) { if (new_lck->ltype == F_RDLCK && ltype == F_WRLCK) { @@ -486,6 +491,7 @@ int tdb_allrecord_lock(struct tdb_context *tdb, int ltype, return -1; } + add_stat(tdb, locks, 1); again: /* Lock hashes, gradually. */ if (tdb_lock_gradual(tdb, ltype, flags, TDB_HASH_LOCK_START, diff --git a/ccan/tdb2/private.h b/ccan/tdb2/private.h index 6e9936f5..1a81286d 100644 --- a/ccan/tdb2/private.h +++ b/ccan/tdb2/private.h @@ -331,6 +331,8 @@ struct tdb_context { uint64_t num_lockrecs; struct tdb_lock_type *lockrecs; + struct tdb_attribute_stats *stats; + /* Single list of all TDBs, to avoid multiple opens. */ struct tdb_context *next; dev_t device; @@ -466,6 +468,13 @@ int tdb_write_convert(struct tdb_context *tdb, tdb_off_t off, int tdb_read_convert(struct tdb_context *tdb, tdb_off_t off, void *rec, size_t len); +/* Adds a stat, if it's in range. */ +void add_stat_(struct tdb_context *tdb, uint64_t *stat, size_t val); +#define add_stat(tdb, statname, val) \ + do { \ + if (unlikely((tdb)->stats)) \ + add_stat_((tdb), &(tdb)->stats->statname, (val)); \ + } while (0) /* lock.c: */ void tdb_lock_init(struct tdb_context *tdb); diff --git a/ccan/tdb2/tdb.c b/ccan/tdb2/tdb.c index f7a6a5b3..bd5c2681 100644 --- a/ccan/tdb2/tdb.c +++ b/ccan/tdb2/tdb.c @@ -177,6 +177,7 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, tdb->log = null_log_fn; tdb->log_priv = NULL; tdb->transaction = NULL; + tdb->stats = NULL; tdb_hash_init(tdb); tdb_io_init(tdb); tdb_lock_init(tdb); @@ -194,6 +195,12 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, case TDB_ATTRIBUTE_SEED: seed = &attr->seed; break; + case TDB_ATTRIBUTE_STATS: + tdb->stats = &attr->stats; + /* They have stats we don't know about? Tell them. */ + if (tdb->stats->size > sizeof(attr->stats)) + tdb->stats->size = sizeof(attr->stats); + break; default: tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, "tdb_open: unknown attribute type %u\n", @@ -386,6 +393,7 @@ static int replace_data(struct tdb_context *tdb, /* We didn't like the existing one: remove it. */ if (old_off) { + add_stat(tdb, frees, 1); add_free_record(tdb, old_off, sizeof(struct tdb_used_record) + key.dsize + old_room); @@ -582,6 +590,7 @@ int tdb_delete(struct tdb_context *tdb, struct tdb_data key) goto unlock_err; /* Free the deleted entry. */ + add_stat(tdb, frees, 1); if (add_free_record(tdb, off, sizeof(struct tdb_used_record) + rec_key_length(&rec) diff --git a/ccan/tdb2/tdb2.h b/ccan/tdb2/tdb2.h index 5050b3fd..232d72a5 100644 --- a/ccan/tdb2/tdb2.h +++ b/ccan/tdb2/tdb2.h @@ -87,7 +87,8 @@ typedef uint64_t (*tdb_hashfn_t)(const void *key, size_t len, uint64_t seed, enum tdb_attribute_type { TDB_ATTRIBUTE_LOG = 0, TDB_ATTRIBUTE_HASH = 1, - TDB_ATTRIBUTE_SEED = 2 + TDB_ATTRIBUTE_SEED = 2, + TDB_ATTRIBUTE_STATS = 3 }; struct tdb_attribute_base { @@ -112,11 +113,32 @@ struct tdb_attribute_seed { uint64_t seed; }; +struct tdb_attribute_stats { + struct tdb_attribute_base base; /* .attr = TDB_ATTRIBUTE_STATS */ + size_t size; /* = sizeof(struct tdb_attribute_stats) */ + uint64_t allocs; + uint64_t alloc_subhash; + uint64_t alloc_bucket_exact; + uint64_t alloc_bucket_max; + uint64_t alloc_leftover; + uint64_t alloc_coalesce_tried; + uint64_t alloc_coalesce_lockfail; + uint64_t alloc_coalesce_race; + uint64_t alloc_coalesce_succeeded; + uint64_t alloc_coalesce_num_merged; + uint64_t expands; + uint64_t frees; + uint64_t locks; + uint64_t lock_lowlevel; + uint64_t lock_nonblock; +}; + union tdb_attribute { struct tdb_attribute_base base; struct tdb_attribute_log log; struct tdb_attribute_hash hash; struct tdb_attribute_seed seed; + struct tdb_attribute_stats stats; }; struct tdb_context *tdb_open(const char *name, int tdb_flags, diff --git a/ccan/tdb2/tools/speed.c b/ccan/tdb2/tools/speed.c index 84dff996..7a100d0a 100644 --- a/ccan/tdb2/tools/speed.c +++ b/ccan/tdb2/tools/speed.c @@ -43,6 +43,43 @@ static int count_record(struct tdb_context *tdb, return 0; } +static void dump_and_clear_stats(struct tdb_attribute_stats *stats) +{ + printf("allocs = %llu\n", + (unsigned long long)stats->allocs); + printf(" alloc_subhash = %llu\n", + (unsigned long long)stats->alloc_subhash); + printf(" alloc_bucket_exact = %llu\n", + (unsigned long long)stats->alloc_bucket_exact); + printf(" alloc_bucket_max = %llu\n", + (unsigned long long)stats->alloc_bucket_max); + printf(" alloc_leftover = %llu\n", + (unsigned long long)stats->alloc_leftover); + printf(" alloc_coalesce_tried = %llu\n", + (unsigned long long)stats->alloc_coalesce_tried); + printf(" alloc_coalesce_lockfail = %llu\n", + (unsigned long long)stats->alloc_coalesce_lockfail); + printf(" alloc_coalesce_race = %llu\n", + (unsigned long long)stats->alloc_coalesce_race); + printf(" alloc_coalesce_succeeded = %llu\n", + (unsigned long long)stats->alloc_coalesce_succeeded); + printf(" alloc_coalesce_num_merged = %llu\n", + (unsigned long long)stats->alloc_coalesce_num_merged); + printf("expands = %llu\n", + (unsigned long long)stats->expands); + printf("frees = %llu\n", + (unsigned long long)stats->frees); + printf("locks = %llu\n", + (unsigned long long)stats->locks); + printf(" lock_lowlevel = %llu\n", + (unsigned long long)stats->lock_lowlevel); + printf(" lock_nonblock = %llu\n", + (unsigned long long)stats->lock_nonblock); + + /* Now clear. */ + memset(&stats->allocs, 0, (char *)(stats+1) - (char *)&stats->allocs); +} + int main(int argc, char *argv[]) { unsigned int i, j, num = 1000, stage = 0, stopat = -1; @@ -51,13 +88,18 @@ int main(int argc, char *argv[]) TDB_DATA key, data; struct tdb_context *tdb; struct timeval start, stop; - union tdb_attribute seed; + union tdb_attribute seed, stats; /* Try to keep benchmarks even. */ seed.base.attr = TDB_ATTRIBUTE_SEED; seed.base.next = NULL; seed.seed.seed = 0; + memset(&stats, 0, sizeof(stats)); + stats.base.attr = TDB_ATTRIBUTE_STATS; + stats.base.next = NULL; + stats.stats.size = sizeof(stats); + if (argv[1] && strcmp(argv[1], "--internal") == 0) { flags = TDB_INTERNAL; argc--; @@ -68,6 +110,11 @@ int main(int argc, char *argv[]) argc--; argv++; } + if (argv[1] && strcmp(argv[1], "--stats") == 0) { + seed.base.next = &stats; + argc--; + argv++; + } tdb = tdb_open("/tmp/speed.tdb", flags, O_RDWR|O_CREAT|O_TRUNC, 0600, &seed); @@ -105,6 +152,9 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -126,6 +176,8 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -146,6 +198,8 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -165,6 +219,8 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -185,6 +241,8 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -205,6 +263,8 @@ int main(int argc, char *argv[]) errx(1, "committing transaction: %s", tdb_errorstr(tdb)); printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); if (++stage == stopat) exit(0); @@ -248,5 +308,10 @@ int main(int argc, char *argv[]) printf(" %zu ns (%zu bytes)\n", normalize(&start, &stop, num), file_size()); + if (seed.base.next) + dump_and_clear_stats(&stats.stats); + if (++stage == stopat) + exit(0); + return 0; } diff --git a/ccan/tdb2/transaction.c b/ccan/tdb2/transaction.c index 927c6299..0aad8de8 100644 --- a/ccan/tdb2/transaction.c +++ b/ccan/tdb2/transaction.c @@ -621,6 +621,7 @@ static int tdb_recovery_allocate(struct tdb_context *tdb, us an area that is being currently used (as of the start of the transaction) */ if (recovery_head != 0) { + add_stat(tdb, frees, 1); if (add_free_record(tdb, recovery_head, sizeof(rec) + rec.max_len) != 0) { tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, -- 2.39.2