From: Rusty Russell Date: Wed, 1 Dec 2010 12:41:51 +0000 (+1030) Subject: tdb2: clean up logging X-Git-Url: https://git.ozlabs.org/?p=ccan;a=commitdiff_plain;h=4e185ad8ab5a7e01edbbe12d11eb2f1577de7e8b tdb2: clean up logging Logged errors should always set tdb->ecode before they are called, and there's little reason to have a sprintf-style logging function since we can do the formatting internally. Change the tdb_log attribute to just take a "const char *", and create a new tdb_logerr() helper which sets ecode and calls it. As a bonus, mark it COLD so the compiler can optimize appropriately knowing that it's unlikely to be invoked. --- diff --git a/ccan/tdb2/check.c b/ccan/tdb2/check.c index 1ce56c2c..dc18e64a 100644 --- a/ccan/tdb2/check.c +++ b/ccan/tdb2/check.c @@ -43,25 +43,25 @@ static bool check_header(struct tdb_context *tdb, tdb_off_t *recovery) hash_test = TDB_HASH_MAGIC; hash_test = tdb_hash(tdb, &hash_test, sizeof(hash_test)); if (hdr.hash_test != hash_test) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "check: hash test %llu should be %llu\n", - (long long)hdr.hash_test, - (long long)hash_test); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "check: hash test %llu should be %llu", + (long long)hdr.hash_test, + (long long)hash_test); return false; } if (strcmp(hdr.magic_food, TDB_MAGIC_FOOD) != 0) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "check: bad magic '%.*s'\n", - (unsigned)sizeof(hdr.magic_food), hdr.magic_food); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "check: bad magic '%.*s'", + (unsigned)sizeof(hdr.magic_food), hdr.magic_food); return false; } *recovery = hdr.recovery; if (*recovery) { if (*recovery < sizeof(hdr) || *recovery > tdb->map_size) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: invalid recovery offset %zu\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: invalid recovery offset %zu", (size_t)*recovery); return false; } @@ -98,21 +98,22 @@ static bool check_hash_record(struct tdb_context *tdb, if (rec_data_length(&rec) != sizeof(tdb_off_t) << TDB_SUBLEVEL_HASH_BITS) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Bad hash table length %llu vs %llu\n", - (long long)rec_data_length(&rec), - (long long)sizeof(tdb_off_t)<log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Bad hash table key length %llu\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: Bad hash table key length %llu", (long long)rec_key_length(&rec)); return false; } if (rec_hash(&rec) != 0) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Bad hash table hash value %llu\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: Bad hash table hash value %llu", (long long)rec_hash(&rec)); return false; } @@ -172,10 +173,10 @@ static bool check_hash_tree(struct tdb_context *tdb, off = group[b] & TDB_OFF_MASK; p = asearch(&off, used, num_used, off_cmp); if (!p) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Invalid offset %llu " - "in hash\n", - (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: Invalid offset %llu " + "in hash", (long long)off); goto fail; } /* Mark it invalid. */ @@ -206,18 +207,20 @@ static bool check_hash_tree(struct tdb_context *tdb, used_bits = 0; if (get_bits(h, hprefix_bits, &used_bits) != hprefix && hprefix_bits) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "check: bad hash placement" - " 0x%llx vs 0x%llx\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "check: bad hash placement" + " 0x%llx vs 0x%llx", (long long)h, (long long)hprefix); goto fail; } /* Does it belong in this group? */ if (get_bits(h, group_bits, &used_bits) != g) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "check: bad group %llu vs %u\n", - (long long)h, g); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "check: bad group %llu vs %u", + (long long)h, g); goto fail; } @@ -226,11 +229,12 @@ static bool check_hash_tree(struct tdb_context *tdb, if (get_bits(h, TDB_HASH_GROUP_BITS, &used_bits) != bucket) { used_bits -= TDB_HASH_GROUP_BITS; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "check: bad bucket %u vs %u\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "check: bad bucket %u vs %u", (unsigned)get_bits(h, - TDB_HASH_GROUP_BITS, - &used_bits), + TDB_HASH_GROUP_BITS, + &used_bits), bucket); goto fail; } @@ -241,26 +245,27 @@ static bool check_hash_tree(struct tdb_context *tdb, i != b; i = (i + 1) % (1 << TDB_HASH_GROUP_BITS)) { if (group[i] == 0) { - tdb->log(tdb, TDB_DEBUG_ERROR, - tdb->log_priv, - "check: bad group placement" - " %u vs %u\n", - b, bucket); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "check: bad group placement" + " %u vs %u", + b, bucket); goto fail; } } - if (tdb_read_convert(tdb, off, &rec, sizeof(rec)) == -1) + if (tdb_read_convert(tdb, off, &rec, sizeof(rec))) goto fail; /* Bottom bits must match header. */ if ((h & ((1 << 11)-1)) != rec_hash(&rec)) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Bad hash magic at" - " offset %llu (0x%llx vs 0x%llx)\n", - (long long)off, - (long long)h, - (long long)rec_hash(&rec)); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: Bad hash magic at" + " offset %llu (0x%llx vs 0x%llx)", + (long long)off, + (long long)h, + (long long)rec_hash(&rec)); goto fail; } @@ -305,8 +310,8 @@ static bool check_hash(struct tdb_context *tdb, return false; if (num_found != num_used) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Not all entries are in hash\n"); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: Not all entries are in hash"); return false; } return true; @@ -318,15 +323,15 @@ static bool check_free(struct tdb_context *tdb, tdb_off_t prev, unsigned int flist, unsigned int bucket) { if (frec_magic(frec) != TDB_FREE_MAGIC) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: offset %llu bad magic 0x%llx\n", - (long long)off, (long long)frec->magic_and_prev); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: offset %llu bad magic 0x%llx", + (long long)off, (long long)frec->magic_and_prev); return false; } if (frec_flist(frec) != flist) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: offset %llu bad freelist %u\n", - (long long)off, frec_flist(frec)); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: offset %llu bad freelist %u", + (long long)off, frec_flist(frec)); return false; } @@ -335,17 +340,17 @@ static bool check_free(struct tdb_context *tdb, false)) return false; if (size_to_bucket(frec_len(frec)) != bucket) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: offset %llu in wrong bucket %u vs %u\n", - (long long)off, - bucket, size_to_bucket(frec_len(frec))); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: offset %llu in wrong bucket %u vs %u", + (long long)off, + bucket, size_to_bucket(frec_len(frec))); return false; } if (prev != frec_prev(frec)) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: offset %llu bad prev %llu vs %llu\n", - (long long)off, - (long long)prev, (long long)frec_len(frec)); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: offset %llu bad prev %llu vs %llu", + (long long)off, + (long long)prev, (long long)frec_len(frec)); return false; } return true; @@ -369,9 +374,8 @@ static bool check_free_list(struct tdb_context *tdb, || rec_key_length(&flist.hdr) != 0 || rec_data_length(&flist.hdr) != sizeof(flist) - sizeof(flist.hdr) || rec_hash(&flist.hdr) != 1) { - tdb->log(tdb, TDB_DEBUG_ERROR, - tdb->log_priv, - "tdb_check: Invalid header on free list\n"); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: Invalid header on free list"); return false; } @@ -391,11 +395,11 @@ static bool check_free_list(struct tdb_context *tdb, /* FIXME: Check hash bits */ p = asearch(&off, free, num_free, off_cmp); if (!p) { - tdb->log(tdb, TDB_DEBUG_ERROR, - tdb->log_priv, - "tdb_check: Invalid offset" - " %llu in free table\n", - (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: Invalid offset" + " %llu in free table", + (long long)off); return false; } /* Mark it invalid. */ @@ -453,38 +457,42 @@ static bool check_linear(struct tdb_context *tdb, } else { len = dead_space(tdb, off); if (len < sizeof(rec.r)) { - tdb->log(tdb, TDB_DEBUG_ERROR, - tdb->log_priv, - "tdb_check: invalid dead space" - " at %zu\n", (size_t)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: invalid dead" + " space at %zu", + (size_t)off); return false; } - tdb->log(tdb, TDB_DEBUG_WARNING, tdb->log_priv, - "Dead space at %zu-%zu (of %zu)\n", - (size_t)off, (size_t)(off + len), - (size_t)tdb->map_size); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_WARNING, + "Dead space at %zu-%zu (of %zu)", + (size_t)off, (size_t)(off + len), + (size_t)tdb->map_size); } } else if (rec.r.magic == TDB_RECOVERY_MAGIC) { if (tdb_read_convert(tdb, off, &rec, sizeof(rec.r))) return false; if (recovery != off) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: unexpected recovery" - " record at offset %zu\n", - (size_t)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: unexpected recovery" + " record at offset %zu", + (size_t)off); return false; } if (rec.r.len > rec.r.max_len) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: invalid recovery length" - " %zu\n", (size_t)rec.r.len); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: invalid recovery length" + " %zu", (size_t)rec.r.len); return false; } if (rec.r.eof > tdb->map_size) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: invalid old EOF" - " %zu\n", (size_t)rec.r.eof); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: invalid old EOF" + " %zu", (size_t)rec.r.eof); return false; } found_recovery = true; @@ -493,10 +501,11 @@ static bool check_linear(struct tdb_context *tdb, || frec_magic(&rec.f) == TDB_COALESCING_MAGIC) { len = sizeof(rec.u) + frec_len(&rec.f); if (off + len > tdb->map_size) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: free overlength %llu" - " at offset %llu\n", - (long long)len, (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: free overlength %llu" + " at offset %llu", + (long long)len, (long long)off); return false; } /* This record is free! */ @@ -508,11 +517,12 @@ static bool check_linear(struct tdb_context *tdb, /* This record is used! */ if (rec_magic(&rec.u) != TDB_MAGIC) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Bad magic 0x%llx" - " at offset %llu\n", - (long long)rec_magic(&rec.u), - (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: Bad magic 0x%llx" + " at offset %zu", + (long long)rec_magic(&rec.u), + (size_t)off); return false; } @@ -525,18 +535,20 @@ static bool check_linear(struct tdb_context *tdb, len = sizeof(rec.u) + klen + dlen + extra; if (off + len > tdb->map_size) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: used overlength %llu" - " at offset %llu\n", - (long long)len, (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: used overlength %llu" + " at offset %llu", + (long long)len, (long long)off); return false; } if (len < sizeof(rec.f)) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: too short record %llu at" - " %llu\n", - (long long)len, (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_ERROR, + "tdb_check: too short record %llu" + " at %llu", + (long long)len, (long long)off); return false; } } @@ -544,9 +556,9 @@ static bool check_linear(struct tdb_context *tdb, /* We must have found recovery area if there was one. */ if (recovery != 0 && !found_recovery) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: expected a recovery area at %zu\n", - (size_t)recovery); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: expected a recovery area at %zu", + (size_t)recovery); return false; } @@ -589,8 +601,8 @@ int tdb_check(struct tdb_context *tdb, goto fail; if (num_found != num_free) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_check: Not all entries are in free table\n"); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_ERROR, + "tdb_check: Not all entries are in free table"); return -1; } diff --git a/ccan/tdb2/free.c b/ccan/tdb2/free.c index 48ea2b20..49880f18 100644 --- a/ccan/tdb2/free.c +++ b/ccan/tdb2/free.c @@ -118,8 +118,8 @@ static int remove_from_list(struct tdb_context *tdb, #ifdef DEBUG if (tdb_read_off(tdb, off) != r_off) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "remove_from_list: %llu bad prev in list %llu\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "remove_from_list: %llu bad prev in list %llu", (long long)r_off, (long long)b_off); return -1; } @@ -136,9 +136,9 @@ static int remove_from_list(struct tdb_context *tdb, #ifdef DEBUG if (tdb_read_off(tdb, off) & TDB_OFF_MASK != r_off) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "remove_from_list: %llu bad list %llu\n", - (long long)r_off, (long long)b_off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "remove_from_list: %llu bad list %llu", + (long long)r_off, (long long)b_off); return -1; } #endif @@ -176,9 +176,10 @@ static int enqueue_in_free(struct tdb_context *tdb, new.next + offsetof(struct tdb_free_record, magic_and_prev)) != magic) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "enqueue_in_free: %llu bad head prev %llu\n", - (long long)new.next, (long long)b_off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "enqueue_in_free: %llu bad head" + " prev %llu", + (long long)new.next, (long long)b_off); return -1; } #endif @@ -331,10 +332,9 @@ static int coalesce(struct tdb_context *tdb, goto err; if (frec_len(&rec) != data_len) { - tdb->ecode = TDB_ERR_CORRUPT; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "coalesce: expected data len %llu not %llu\n", - (long long)data_len, (long long)frec_len(&rec)); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "coalesce: expected data len %zu not %zu", + (size_t)data_len, (size_t)frec_len(&rec)); goto err; } @@ -412,8 +412,8 @@ again: if (frec_magic(r) != TDB_FREE_MAGIC) { tdb_access_release(tdb, r); - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "lock_and_alloc: %llu non-free 0x%llx\n", + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "lock_and_alloc: %llu non-free 0x%llx", (long long)off, (long long)r->magic_and_prev); goto unlock_err; } @@ -566,9 +566,8 @@ int set_used_header(struct tdb_context *tdb, if (rec_key_length(rec) != keylen || rec_data_length(rec) != datalen || rec_extra_padding(rec) != actuallen - (keylen + datalen)) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "Could not encode k=%llu,d=%llu,a=%llu\n", + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "Could not encode k=%llu,d=%llu,a=%llu", (long long)keylen, (long long)datalen, (long long)actuallen); return -1; @@ -588,8 +587,8 @@ static int tdb_expand(struct tdb_context *tdb, tdb_len_t size) /* Need to hold a hash lock to expand DB: transactions rely on it. */ if (!(tdb->flags & TDB_NOLOCK) && !tdb->allrecord_lock.count && !tdb_has_hash_locks(tdb)) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_expand: must hold lock during expand\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_expand: must hold lock during expand"); return -1; } diff --git a/ccan/tdb2/hash.c b/ccan/tdb2/hash.c index 69df151e..a8a701ec 100644 --- a/ccan/tdb2/hash.c +++ b/ccan/tdb2/hash.c @@ -561,10 +561,11 @@ int next_in_hash(struct tdb_context *tdb, int ltype, return -1; } if (rec_magic(&rec) != TDB_MAGIC) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "next_in_hash:" - " corrupt record at %llu\n", - (long long)off); + tdb_logerr(tdb, TDB_ERR_CORRUPT, + TDB_DEBUG_FATAL, + "next_in_hash:" + " corrupt record at %llu", + (long long)off); return -1; } diff --git a/ccan/tdb2/io.c b/ccan/tdb2/io.c index 56ccfcba..82c49406 100644 --- a/ccan/tdb2/io.c +++ b/ccan/tdb2/io.c @@ -56,9 +56,9 @@ void tdb_mmap(struct tdb_context *tdb) */ if (tdb->map_ptr == MAP_FAILED) { tdb->map_ptr = NULL; - tdb->log(tdb, TDB_DEBUG_WARNING, tdb->log_priv, - "tdb_mmap failed for size %lld (%s)\n", - (long long)tdb->map_size, strerror(errno)); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_WARNING, + "tdb_mmap failed for size %lld (%s)", + (long long)tdb->map_size, strerror(errno)); } } @@ -70,7 +70,6 @@ void tdb_mmap(struct tdb_context *tdb) static int tdb_oob(struct tdb_context *tdb, tdb_off_t len, bool probe) { struct stat st; - int ret; /* We can't hold pointers during this: we could unmap! */ assert(!tdb->direct_access @@ -81,11 +80,9 @@ static int tdb_oob(struct tdb_context *tdb, tdb_off_t len, bool probe) return 0; if (tdb->flags & TDB_INTERNAL) { if (!probe) { - /* Ensure ecode is set for log fn. */ - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, "tdb_oob len %lld beyond internal" - " malloc size %lld\n", + " malloc size %lld", (long long)len, (long long)tdb->map_size); } @@ -95,22 +92,20 @@ static int tdb_oob(struct tdb_context *tdb, tdb_off_t len, bool probe) if (tdb_lock_expand(tdb, F_RDLCK) != 0) return -1; - ret = fstat(tdb->fd, &st); - - tdb_unlock_expand(tdb, F_RDLCK); - - if (ret == -1) { - tdb->ecode = TDB_ERR_IO; + if (fstat(tdb->fd, &st) != 0) { + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "Failed to fstat file: %s", strerror(errno)); + tdb_unlock_expand(tdb, F_RDLCK); return -1; } + tdb_unlock_expand(tdb, F_RDLCK); + if (st.st_size < (size_t)len) { if (!probe) { - /* Ensure ecode is set for log fn. */ - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_oob len %lld beyond eof at %lld\n", - (long long)len, (long long)st.st_size); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_oob len %zu beyond eof at %zu", + (size_t)len, st.st_size); } return -1; } @@ -180,11 +175,7 @@ int zero_out(struct tdb_context *tdb, tdb_off_t off, tdb_len_t len) char buf[8192] = { 0 }; void *p = tdb->methods->direct(tdb, off, len); - if (tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; - return -1; - } - + assert(!tdb->read_only); if (p) { memset(p, 0, len); return 0; @@ -275,15 +266,17 @@ bool tdb_read_all(int fd, void *buf, size_t len) static int tdb_write(struct tdb_context *tdb, tdb_off_t off, const void *buf, tdb_len_t len) { - if (len == 0) { - return 0; - } - if (tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; + tdb_logerr(tdb, TDB_ERR_RDONLY, TDB_DEBUG_WARNING, + "Write to read-only database"); return -1; } + /* FIXME: Bogus optimization? */ + if (len == 0) { + return 0; + } + if (tdb->methods->oob(tdb, off + len, 0) != 0) return -1; @@ -291,11 +284,9 @@ static int tdb_write(struct tdb_context *tdb, tdb_off_t off, memcpy(off + (char *)tdb->map_ptr, buf, len); } else { if (!tdb_pwrite_all(tdb->fd, buf, len, off)) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_write failed at %llu len=%llu (%s)\n", - (long long)off, (long long)len, - strerror(errno)); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_write failed at %zu len=%zu (%s)", + (size_t)off, (size_t)len, strerror(errno)); return -1; } } @@ -314,14 +305,12 @@ static int tdb_read(struct tdb_context *tdb, tdb_off_t off, void *buf, memcpy(buf, off + (char *)tdb->map_ptr, len); } else { if (!tdb_pread_all(tdb->fd, buf, len, off)) { - /* Ensure ecode is set for log fn. */ - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_read failed at %lld " - "len=%lld (%s) map_size=%lld\n", - (long long)off, (long long)len, + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_read failed at %zu " + "len=%zu (%s) map_size=%zu", + (size_t)off, (size_t)len, strerror(errno), - (long long)tdb->map_size); + (size_t)tdb->map_size); return -1; } } @@ -335,10 +324,9 @@ int tdb_write_convert(struct tdb_context *tdb, tdb_off_t off, if (unlikely((tdb->flags & TDB_CONVERT))) { void *conv = malloc(len); if (!conv) { - tdb->ecode = TDB_ERR_OOM; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_write: no memory converting %zu bytes\n", - len); + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "tdb_write: no memory converting" + " %zu bytes", len); return -1; } memcpy(conv, rec, len); @@ -362,7 +350,8 @@ int tdb_read_convert(struct tdb_context *tdb, tdb_off_t off, int tdb_write_off(struct tdb_context *tdb, tdb_off_t off, tdb_off_t val) { if (tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; + tdb_logerr(tdb, TDB_ERR_RDONLY, TDB_DEBUG_WARNING, + "Write to read-only database"); return -1; } @@ -383,12 +372,12 @@ static void *_tdb_alloc_read(struct tdb_context *tdb, tdb_off_t offset, /* some systems don't like zero length malloc */ buf = malloc(prefix + len ? prefix + len : 1); - if (unlikely(!buf)) { - tdb->ecode = TDB_ERR_OOM; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_alloc_read malloc failed len=%lld\n", - (long long)prefix + len); - } else if (unlikely(tdb->methods->read(tdb, offset, buf+prefix, len))) { + if (!buf) { + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_ERROR, + "tdb_alloc_read malloc failed len=%zu", + (size_t)(prefix + len)); + } else if (unlikely(tdb->methods->read(tdb, offset, buf+prefix, + len) == -1)) { free(buf); buf = NULL; } @@ -409,9 +398,8 @@ static int fill(struct tdb_context *tdb, size_t n = len > size ? size : len; if (!tdb_pwrite_all(tdb->fd, buf, n, off)) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "fill write failed: giving up!\n"); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "fill write failed: giving up!"); return -1; } len -= n; @@ -427,14 +415,16 @@ static int tdb_expand_file(struct tdb_context *tdb, tdb_len_t addition) char buf[8192]; if (tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; + tdb_logerr(tdb, TDB_ERR_RDONLY, TDB_DEBUG_WARNING, + "Expand on read-only database"); return -1; } if (tdb->flags & TDB_INTERNAL) { char *new = realloc(tdb->map_ptr, tdb->map_size + addition); if (!new) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "No memory to expand database"); return -1; } tdb->map_ptr = new; @@ -495,7 +485,8 @@ void *tdb_access_write(struct tdb_context *tdb, void *ret = NULL; if (tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; + tdb_logerr(tdb, TDB_ERR_RDONLY, TDB_DEBUG_WARNING, + "Write to read-only database"); return NULL; } diff --git a/ccan/tdb2/lock.c b/ccan/tdb2/lock.c index 65e9dc25..0b30af54 100644 --- a/ccan/tdb2/lock.c +++ b/ccan/tdb2/lock.c @@ -102,7 +102,7 @@ static int fcntl_unlock(struct tdb_context *tdb, int rw, off_t off, off_t len) } if (!found) { - fprintf(stderr, "Unlock on %u@%u not found!\n", + fprintf(stderr, "Unlock on %u@%u not found!", (int)off, (int)len); abort(); } @@ -135,16 +135,16 @@ static int tdb_brlock(struct tdb_context *tdb, } if (rw_type == F_WRLCK && tdb->read_only) { - tdb->ecode = TDB_ERR_RDONLY; + tdb_logerr(tdb, TDB_ERR_RDONLY, TDB_DEBUG_WARNING, + "Write lock attempted on read-only database"); return -1; } /* A 32 bit system cannot open a 64-bit file, but it could have * expanded since then: check here. */ if ((size_t)(offset + len) != offset + len) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_brlock: lock on giant offset %llu\n", + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_brlock: lock on giant offset %llu", (long long)(offset + len)); return -1; } @@ -160,11 +160,12 @@ static int tdb_brlock(struct tdb_context *tdb, * EAGAIN is an expected return from non-blocking * locks. */ if (!(flags & TDB_LOCK_PROBE) && errno != EAGAIN) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_brlock failed (fd=%d) at" - " offset %llu rw_type=%d flags=%d len=%llu\n", - tdb->fd, (long long)offset, rw_type, - flags, (long long)len); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_brlock failed (fd=%d) at" + " offset %zu rw_type=%d flags=%d len=%zu:" + " %s", + tdb->fd, (size_t)offset, rw_type, + flags, (size_t)len, strerror(errno)); } return -1; } @@ -185,10 +186,10 @@ static int tdb_brunlock(struct tdb_context *tdb, } while (ret == -1 && errno == EINTR); if (ret == -1) { - tdb->log(tdb, TDB_DEBUG_TRACE, tdb->log_priv, - "tdb_brunlock failed (fd=%d) at offset %llu" - " rw_type=%d len=%llu\n", - tdb->fd, (long long)offset, rw_type, (long long)len); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_TRACE, + "tdb_brunlock failed (fd=%d) at offset %zu" + " rw_type=%d len=%zu", + tdb->fd, (size_t)offset, rw_type, (size_t)len); } return ret; } @@ -204,15 +205,15 @@ int tdb_allrecord_upgrade(struct tdb_context *tdb) int count = 1000; if (tdb->allrecord_lock.count != 1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_upgrade failed: count %u too high\n", - tdb->allrecord_lock.count); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_upgrade failed: count %u too high", + tdb->allrecord_lock.count); return -1; } if (tdb->allrecord_lock.off != 1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_upgrade failed: already upgraded?\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_upgrade failed: already upgraded?"); return -1; } @@ -233,8 +234,8 @@ int tdb_allrecord_upgrade(struct tdb_context *tdb) tv.tv_usec = 1; select(0, NULL, NULL, NULL, &tv); } - tdb->log(tdb, TDB_DEBUG_WARNING, tdb->log_priv, - "tdb_allrecord_upgrade failed\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_WARNING, + "tdb_allrecord_upgrade failed"); return -1; } @@ -279,10 +280,9 @@ static int tdb_nest_lock(struct tdb_context *tdb, tdb_off_t offset, int ltype, struct tdb_lock_type *new_lck; if (offset > TDB_HASH_LOCK_START + TDB_HASH_LOCK_RANGE + tdb->map_size / 8) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_nest_lock: invalid offset %llu ltype=%d\n", - (long long)offset, ltype); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_FATAL, + "tdb_nest_lock: invalid offset %zu ltype=%d", + (size_t)offset, ltype); return -1; } @@ -294,10 +294,9 @@ static int tdb_nest_lock(struct tdb_context *tdb, tdb_off_t offset, int ltype, new_lck = find_nestlock(tdb, offset); if (new_lck) { if (new_lck->ltype == F_RDLCK && ltype == F_WRLCK) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_nest_lock: offset %llu has read lock\n", - (long long)offset); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_FATAL, + "tdb_nest_lock: offset %zu has read lock", + (size_t)offset); return -1; } /* Just increment the struct, posix locks don't stack. */ @@ -308,9 +307,8 @@ static int tdb_nest_lock(struct tdb_context *tdb, tdb_off_t offset, int ltype, if (tdb->num_lockrecs && offset >= TDB_HASH_LOCK_START && offset < TDB_HASH_LOCK_START + TDB_HASH_LOCK_RANGE) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_nest_lock: already have a hash lock?\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_FATAL, + "tdb_nest_lock: already have a hash lock?"); return -1; } @@ -318,10 +316,9 @@ static int tdb_nest_lock(struct tdb_context *tdb, tdb_off_t offset, int ltype, tdb->lockrecs, sizeof(*tdb->lockrecs) * (tdb->num_lockrecs+1)); if (new_lck == NULL) { - tdb->ecode = TDB_ERR_OOM; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_nest_lock: unable to allocate %llu lock struct", - (long long)(tdb->num_lockrecs + 1)); + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_ERROR, + "tdb_nest_lock: unable to allocate %zu lock struct", + tdb->num_lockrecs + 1); errno = ENOMEM; return -1; } @@ -366,9 +363,8 @@ static int tdb_nest_unlock(struct tdb_context *tdb, tdb_off_t off, int ltype) lck = find_nestlock(tdb, off); if ((lck == NULL) || (lck->count == 0)) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_nest_unlock: no lock for %llu\n", (long long)off); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_nest_unlock: no lock for %zu", (size_t)off); return -1; } @@ -453,9 +449,8 @@ int tdb_allrecord_lock(struct tdb_context *tdb, int ltype, { /* FIXME: There are no locks on read-only dbs */ if (tdb->read_only) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock: read-only\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_lock: read-only"); return -1; } @@ -467,27 +462,24 @@ int tdb_allrecord_lock(struct tdb_context *tdb, int ltype, if (tdb->allrecord_lock.count) { /* a global lock of a different type exists */ - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock: already have %s lock\n", - tdb->allrecord_lock.ltype == F_RDLCK - ? "read" : "write"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_lock: already have %s lock", + tdb->allrecord_lock.ltype == F_RDLCK + ? "read" : "write"); return -1; } if (tdb_has_hash_locks(tdb)) { /* can't combine global and chain locks */ - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock: already have chain lock\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_lock: already have chain lock"); return -1; } if (upgradable && ltype != F_RDLCK) { /* tdb error: you can't upgrade a write lock! */ - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock: can't upgrade a write lock\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_lock: can't upgrade a write lock"); return -1; } @@ -497,9 +489,8 @@ again: if (tdb_lock_gradual(tdb, ltype, flags, TDB_HASH_LOCK_START, TDB_HASH_LOCK_RANGE)) { if (!(flags & TDB_LOCK_PROBE)) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock hashes failed (%s)\n", - strerror(errno)); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_ERROR, + "tdb_allrecord_lock hashes failed"); } return -1; } @@ -508,9 +499,8 @@ again: if (tdb_brlock(tdb, ltype, TDB_HASH_LOCK_START + TDB_HASH_LOCK_RANGE, 0, flags)) { if (!(flags & TDB_LOCK_PROBE)) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_lock freelist failed (%s)\n", - strerror(errno)); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_ERROR, + "tdb_allrecord_lock freelist failed"); } tdb_brunlock(tdb, ltype, TDB_HASH_LOCK_START, TDB_HASH_LOCK_RANGE); @@ -565,29 +555,19 @@ void tdb_unlock_expand(struct tdb_context *tdb, int ltype) /* unlock entire db */ int tdb_allrecord_unlock(struct tdb_context *tdb, int ltype) { - /* FIXME: There are no locks on read-only dbs */ - if (tdb->read_only) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_unlock: read-only\n"); - return -1; - } - if (tdb->allrecord_lock.count == 0) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_unlock: not locked!\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_unlock: not locked!"); return -1; } /* Upgradable locks are marked as write locks. */ if (tdb->allrecord_lock.ltype != ltype && (!tdb->allrecord_lock.off || ltype != F_RDLCK)) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_allrecord_unlock: have %s lock\n", - tdb->allrecord_lock.ltype == F_RDLCK - ? "read" : "write"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_allrecord_unlock: have %s lock", + tdb->allrecord_lock.ltype == F_RDLCK + ? "read" : "write"); return -1; } @@ -648,25 +628,22 @@ int tdb_lock_hashes(struct tdb_context *tdb, } if (tdb->allrecord_lock.count) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_lock_hashes: have %s allrecordlock\n", - tdb->allrecord_lock.ltype == F_RDLCK - ? "read" : "write"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_lock_hashes: already have %s allrecordlock", + tdb->allrecord_lock.ltype == F_RDLCK + ? "read" : "write"); return -1; } if (tdb_has_free_lock(tdb)) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_lock_hashes: have free lock already\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_lock_hashes: already have free lock"); return -1; } if (tdb_has_expansion_lock(tdb)) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_lock_hashes: have expansion lock already\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_lock_hashes: already have expansion lock"); return -1; } @@ -684,9 +661,8 @@ int tdb_unlock_hashes(struct tdb_context *tdb, if (tdb->allrecord_lock.count) { if (tdb->allrecord_lock.ltype == F_RDLCK && ltype == F_WRLCK) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_unlock_hashes RO allrecord!\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_FATAL, + "tdb_unlock_hashes RO allrecord!"); return -1; } return 0; @@ -715,17 +691,15 @@ int tdb_lock_free_bucket(struct tdb_context *tdb, tdb_off_t b_off, if (tdb->allrecord_lock.count) { if (tdb->allrecord_lock.ltype == F_WRLCK) return 0; - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_lock_free_bucket with RO allrecordlock!\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_FATAL, + "tdb_lock_free_bucket with RO allrecordlock!"); return -1; } #if 0 /* FIXME */ if (tdb_has_expansion_lock(tdb)) { - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_lock_free_bucket: have expansion lock already\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_lock_free_bucket: already have expansion lock"); return -1; } #endif diff --git a/ccan/tdb2/private.h b/ccan/tdb2/private.h index 232229f5..8601a9a4 100644 --- a/ccan/tdb2/private.h +++ b/ccan/tdb2/private.h @@ -36,6 +36,7 @@ #include "config.h" #include #include +#include #ifdef HAVE_BYTESWAP_H #include #endif @@ -308,8 +309,8 @@ struct tdb_context { uint32_t flags; /* Logging function */ - tdb_logfn_t log; - void *log_priv; + tdb_logfn_t logfn; + void *log_private; /* Hash function. */ tdb_hashfn_t khash; @@ -328,7 +329,7 @@ struct tdb_context { /* Lock information */ struct tdb_lock_type allrecord_lock; - uint64_t num_lockrecs; + size_t num_lockrecs; struct tdb_lock_type *lockrecs; struct tdb_attribute_stats *stats; @@ -529,6 +530,12 @@ int next_in_hash(struct tdb_context *tdb, int ltype, int tdb_transaction_recover(struct tdb_context *tdb); bool tdb_needs_recovery(struct tdb_context *tdb); +/* tdb.c: */ +void COLD tdb_logerr(struct tdb_context *tdb, + enum TDB_ERROR ecode, + enum tdb_debug_level level, + const char *fmt, ...); + #ifdef TDB_TRACE void tdb_trace(struct tdb_context *tdb, const char *op); void tdb_trace_seqnum(struct tdb_context *tdb, uint32_t seqnum, const char *op); diff --git a/ccan/tdb2/summary.c b/ccan/tdb2/summary.c index b54b56e7..42b1163e 100644 --- a/ccan/tdb2/summary.c +++ b/ccan/tdb2/summary.c @@ -164,7 +164,8 @@ char *tdb_summary(struct tdb_context *tdb, enum tdb_summary_flags flags) buckets = tally_new(HISTO_HEIGHT); if (!flists || !hashes || !freet || !keys || !data || !extra || !uncoal || !buckets) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_ERROR, + "tdb_summary: failed to allocate tally structures"); goto unlock; } diff --git a/ccan/tdb2/tdb.c b/ccan/tdb2/tdb.c index bd5c2681..a4dbc53d 100644 --- a/ccan/tdb2/tdb.c +++ b/ccan/tdb2/tdb.c @@ -1,8 +1,7 @@ #include "private.h" #include -#include -#include #include +#include /* The null return. */ struct tdb_data tdb_null = { .dptr = NULL, .dsize = 0 }; @@ -10,13 +9,6 @@ struct tdb_data tdb_null = { .dptr = NULL, .dsize = 0 }; /* all contexts, to ensure no double-opens (fcntl locks don't nest!) */ static struct tdb_context *tdbs = NULL; -PRINTF_FMT(4, 5) static void -null_log_fn(struct tdb_context *tdb, - enum tdb_debug_level level, void *priv, - const char *fmt, ...) -{ -} - static bool tdb_already_open(dev_t device, ino_t ino) { struct tdb_context *i; @@ -39,8 +31,8 @@ static uint64_t random_number(struct tdb_context *tdb) fd = open("/dev/urandom", O_RDONLY); if (fd >= 0) { if (tdb_read_all(fd, &ret, sizeof(ret))) { - tdb->log(tdb, TDB_DEBUG_TRACE, tdb->log_priv, - "tdb_open: random from /dev/urandom\n"); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_TRACE, + "tdb_open: random from /dev/urandom"); close(fd); return ret; } @@ -55,9 +47,9 @@ static uint64_t random_number(struct tdb_context *tdb) char reply[1 + sizeof(uint64_t)]; int r = read(fd, reply, sizeof(reply)); if (r > 1) { - tdb->log(tdb, TDB_DEBUG_TRACE, tdb->log_priv, - "tdb_open: %u random bytes from" - " /dev/egd-pool\n", r-1); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_TRACE, + "tdb_open: %u random bytes from" + " /dev/egd-pool", r-1); /* Copy at least some bytes. */ memcpy(&ret, reply+1, r - 1); if (reply[0] == sizeof(uint64_t) @@ -73,8 +65,8 @@ static uint64_t random_number(struct tdb_context *tdb) /* Fallback: pid and time. */ gettimeofday(&now, NULL); ret = getpid() * 100132289ULL + now.tv_sec * 1000000ULL + now.tv_usec; - tdb->log(tdb, TDB_DEBUG_TRACE, tdb->log_priv, - "tdb_open: random from getpid and time\n"); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_TRACE, + "tdb_open: random from getpid and time"); return ret; } @@ -130,7 +122,8 @@ static int tdb_new_database(struct tdb_context *tdb, tdb->map_size = sizeof(newdb); tdb->map_ptr = malloc(tdb->map_size); if (!tdb->map_ptr) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "tdb_new_database: failed to allocate"); return -1; } memcpy(tdb->map_ptr, &newdb, tdb->map_size); @@ -143,7 +136,9 @@ static int tdb_new_database(struct tdb_context *tdb, return -1; if (!tdb_pwrite_all(tdb->fd, &newdb, sizeof(newdb), 0)) { - tdb->ecode = TDB_ERR_IO; + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_new_database: failed to write: %s", + strerror(errno)); return -1; } return 0; @@ -155,7 +150,7 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, { struct tdb_context *tdb; struct stat st; - int save_errno; + int saved_errno = 0; uint64_t hash_test; unsigned v; struct tdb_header hdr; @@ -165,7 +160,7 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, if (!tdb) { /* Can't log this */ errno = ENOMEM; - goto fail; + return NULL; } tdb->name = NULL; tdb->map_ptr = NULL; @@ -174,8 +169,7 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, tdb->map_size = sizeof(struct tdb_header); tdb->ecode = TDB_SUCCESS; tdb->flags = tdb_flags; - tdb->log = null_log_fn; - tdb->log_priv = NULL; + tdb->logfn = NULL; tdb->transaction = NULL; tdb->stats = NULL; tdb_hash_init(tdb); @@ -185,8 +179,8 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, while (attr) { switch (attr->base.attr) { case TDB_ATTRIBUTE_LOG: - tdb->log = attr->log.log_fn; - tdb->log_priv = attr->log.log_private; + tdb->logfn = attr->log.log_fn; + tdb->log_private = attr->log.log_private; break; case TDB_ATTRIBUTE_HASH: tdb->khash = attr->hash.hash_fn; @@ -202,19 +196,17 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, tdb->stats->size = sizeof(attr->stats); break; default: - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: unknown attribute type %u\n", - attr->base.attr); - errno = EINVAL; + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_open: unknown attribute type %u", + attr->base.attr); goto fail; } attr = attr->base.next; } if ((open_flags & O_ACCMODE) == O_WRONLY) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: can't open tdb %s write-only\n", name); - errno = EINVAL; + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_open: can't open tdb %s write-only", name); goto fail; } @@ -232,8 +224,6 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, if (tdb->flags & TDB_INTERNAL) { tdb->flags |= (TDB_NOLOCK | TDB_NOMMAP); if (tdb_new_database(tdb, seed, &hdr) != 0) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: tdb_new_database failed!"); goto fail; } tdb_convert(tdb, &hdr.hash_seed, sizeof(hdr.hash_seed)); @@ -243,10 +233,12 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, } if ((tdb->fd = open(name, open_flags, mode)) == -1) { - tdb->log(tdb, TDB_DEBUG_WARNING, tdb->log_priv, - "tdb_open: could not open file %s: %s\n", - name, strerror(errno)); - goto fail; /* errno set by open(2) */ + /* errno set by open(2) */ + saved_errno = errno; + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: could not open file %s: %s", + name, strerror(errno)); + goto fail; } /* on exec, don't inherit the fd */ @@ -255,19 +247,19 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, /* ensure there is only one process initialising at once */ if (tdb_lock_open(tdb, TDB_LOCK_WAIT|TDB_LOCK_NOCHECK) == -1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: failed to get open lock on %s: %s\n", - name, strerror(errno)); - goto fail; /* errno set by tdb_brlock */ + /* errno set by tdb_brlock */ + saved_errno = errno; + goto fail; } if (!tdb_pread_all(tdb->fd, &hdr, sizeof(hdr), 0) || strcmp(hdr.magic_food, TDB_MAGIC_FOOD) != 0) { - if (!(open_flags & O_CREAT) - || tdb_new_database(tdb, seed, &hdr) == -1) { - if (errno == 0) { - errno = EIO; /* ie bad format or something */ - } + if (!(open_flags & O_CREAT)) { + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: %s is not a tdb file", name); + goto fail; + } + if (tdb_new_database(tdb, seed, &hdr) == -1) { goto fail; } } else if (hdr.version != TDB_VERSION) { @@ -275,10 +267,9 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, tdb->flags |= TDB_CONVERT; else { /* wrong version */ - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: %s is unknown version 0x%llx\n", - name, (long long)hdr.version); - errno = EIO; + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: %s is unknown version 0x%llx", + name, (long long)hdr.version); goto fail; } } @@ -289,29 +280,34 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, hash_test = tdb_hash(tdb, &hash_test, sizeof(hash_test)); if (hdr.hash_test != hash_test) { /* wrong hash variant */ - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: %s uses a different hash function\n", - name); - errno = EIO; + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: %s uses a different hash function", + name); goto fail; } - if (fstat(tdb->fd, &st) == -1) + if (fstat(tdb->fd, &st) == -1) { + saved_errno = errno; + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: could not stat open %s: %s", + name, strerror(errno)); goto fail; + } /* Is it already in the open list? If so, fail. */ if (tdb_already_open(st.st_dev, st.st_ino)) { /* FIXME */ - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: %s (%d,%d) is already open in this process\n", - name, (int)st.st_dev, (int)st.st_ino); - errno = EBUSY; + tdb_logerr(tdb, TDB_ERR_NESTING, TDB_DEBUG_ERROR, + "tdb_open: %s (%d,%d) is already open in this" + " process", + name, (int)st.st_dev, (int)st.st_ino); goto fail; } tdb->name = strdup(name); if (!tdb->name) { - errno = ENOMEM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_ERROR, + "tdb_open: failed to allocate name"); goto fail; } @@ -324,7 +320,6 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, /* Now it's fully formed, recover if necessary. */ if (tdb_needs_recovery(tdb) && tdb_lock_and_recover(tdb) == -1) { - errno = EIO; goto fail; } @@ -336,10 +331,30 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, return tdb; fail: - save_errno = errno; - - if (!tdb) - return NULL; + /* Map ecode to some logical errno. */ + if (!saved_errno) { + switch (tdb->ecode) { + case TDB_ERR_CORRUPT: + case TDB_ERR_IO: + saved_errno = EIO; + break; + case TDB_ERR_LOCK: + saved_errno = EWOULDBLOCK; + break; + case TDB_ERR_OOM: + saved_errno = ENOMEM; + break; + case TDB_ERR_EINVAL: + saved_errno = EINVAL; + break; + case TDB_ERR_NESTING: + saved_errno = EBUSY; + break; + default: + saved_errno = EINVAL; + break; + } + } #ifdef TDB_TRACE close(tdb->tracefd); @@ -353,11 +368,11 @@ struct tdb_context *tdb_open(const char *name, int tdb_flags, free((char *)tdb->name); if (tdb->fd != -1) if (close(tdb->fd) != 0) - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_open: failed to close tdb->fd" - " on error!\n"); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_open: failed to close tdb->fd" + " on error!"); free(tdb); - errno = save_errno; + errno = saved_errno; return NULL; } @@ -515,10 +530,9 @@ int tdb_append(struct tdb_context *tdb, /* Slow path. */ newdata = malloc(key.dsize + old_dlen + dbuf.dsize); if (!newdata) { - tdb->ecode = TDB_ERR_OOM; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_append: cannot allocate %llu bytes!\n", - (long long)key.dsize + old_dlen + dbuf.dsize); + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "tdb_append: failed to allocate %zu bytes", + (size_t)(key.dsize+old_dlen+dbuf.dsize)); goto fail; } if (tdb->methods->read(tdb, off + sizeof(rec) + key.dsize, @@ -646,12 +660,12 @@ int tdb_close(struct tdb_context *tdb) return ret; } -enum TDB_ERROR tdb_error(struct tdb_context *tdb) +enum TDB_ERROR tdb_error(const struct tdb_context *tdb) { return tdb->ecode; } -const char *tdb_errorstr(struct tdb_context *tdb) +const char *tdb_errorstr(const struct tdb_context *tdb) { /* Gcc warns if you miss a case in the switch, so use that. */ switch (tdb->ecode) { @@ -668,3 +682,38 @@ const char *tdb_errorstr(struct tdb_context *tdb) } return "Invalid error code"; } + +void COLD tdb_logerr(struct tdb_context *tdb, + enum TDB_ERROR ecode, + enum tdb_debug_level level, + const char *fmt, ...) +{ + char *message; + va_list ap; + size_t len; + /* tdb_open paths care about errno, so save it. */ + int saved_errno = errno; + + tdb->ecode = ecode; + + if (!tdb->logfn) + return; + + /* FIXME: Doesn't assume asprintf. */ + va_start(ap, fmt); + len = vsnprintf(NULL, 0, fmt, ap); + va_end(ap); + + message = malloc(len + 1); + if (!message) { + tdb->logfn(tdb, level, tdb->log_private, + "out of memory formatting message"); + return; + } + va_start(ap, fmt); + len = vsprintf(message, fmt, ap); + va_end(ap); + tdb->logfn(tdb, level, tdb->log_private, message); + free(message); + errno = saved_errno; +} diff --git a/ccan/tdb2/tdb2.h b/ccan/tdb2/tdb2.h index 232d72a5..ea298db5 100644 --- a/ccan/tdb2/tdb2.h +++ b/ccan/tdb2/tdb2.h @@ -67,7 +67,7 @@ enum TDB_ERROR {TDB_SUCCESS=0, TDB_ERR_CORRUPT, TDB_ERR_IO, TDB_ERR_LOCK, /* flags for tdb_summary. Logical or to combine. */ enum tdb_summary_flags { TDB_SUMMARY_HISTOGRAMS = 1 }; -/* debugging uses one of the following levels */ +/* logging uses one of the following levels */ enum tdb_debug_level {TDB_DEBUG_FATAL = 0, TDB_DEBUG_ERROR, TDB_DEBUG_WARNING, TDB_DEBUG_TRACE}; @@ -80,7 +80,7 @@ struct tdb_context; /* FIXME: Make typesafe */ typedef int (*tdb_traverse_func)(struct tdb_context *, TDB_DATA, TDB_DATA, void *); -typedef void (*tdb_logfn_t)(struct tdb_context *, enum tdb_debug_level, void *priv, const char *, ...) PRINTF_FMT(4, 5); +typedef void (*tdb_logfn_t)(struct tdb_context *, enum tdb_debug_level, void *, const char *); typedef uint64_t (*tdb_hashfn_t)(const void *key, size_t len, uint64_t seed, void *priv); @@ -161,8 +161,8 @@ int tdb_check(struct tdb_context *tdb, int (*check)(TDB_DATA key, TDB_DATA data, void *private_data), void *private_data); -enum TDB_ERROR tdb_error(struct tdb_context *tdb); -const char *tdb_errorstr(struct tdb_context *tdb); +enum TDB_ERROR tdb_error(const struct tdb_context *tdb); +const char *tdb_errorstr(const struct tdb_context *tdb); int tdb_transaction_start(struct tdb_context *tdb); void tdb_transaction_cancel(struct tdb_context *tdb); diff --git a/ccan/tdb2/test/logging.c b/ccan/tdb2/test/logging.c index 85bdc064..8284be13 100644 --- a/ccan/tdb2/test/logging.c +++ b/ccan/tdb2/test/logging.c @@ -1,7 +1,5 @@ -#define _GNU_SOURCE #include #include -#include #include #include "logging.h" @@ -16,24 +14,13 @@ union tdb_attribute tap_log_attr = { void tap_log_fn(struct tdb_context *tdb, enum tdb_debug_level level, void *priv, - const char *fmt, ...) + const char *message) { - va_list ap; - char *p; - if (suppress_logging) return; - va_start(ap, fmt); - if (vasprintf(&p, fmt, ap) == -1) - abort(); - /* Strip trailing \n: diag adds it. */ - if (p[strlen(p)-1] == '\n') - p[strlen(p)-1] = '\0'; - diag("tdb log level %u: %s%s", level, log_prefix, p); - free(p); + diag("tdb log level %u: %s%s", level, log_prefix, message); if (level != TDB_DEBUG_TRACE) tap_log_messages++; - va_end(ap); } diff --git a/ccan/tdb2/test/logging.h b/ccan/tdb2/test/logging.h index 85b417d3..655c00a5 100644 --- a/ccan/tdb2/test/logging.h +++ b/ccan/tdb2/test/logging.h @@ -11,7 +11,7 @@ extern union tdb_attribute tap_log_attr; void tap_log_fn(struct tdb_context *tdb, enum tdb_debug_level level, void *priv, - const char *fmt, ...); + const char *message); static inline bool data_equal(struct tdb_data a, struct tdb_data b) { diff --git a/ccan/tdb2/test/run-001-encode.c b/ccan/tdb2/test/run-001-encode.c index 09b3ab35..3a49fbbf 100644 --- a/ccan/tdb2/test/run-001-encode.c +++ b/ccan/tdb2/test/run-001-encode.c @@ -12,7 +12,7 @@ int main(int argc, char *argv[]) { unsigned int i; struct tdb_used_record rec; - struct tdb_context tdb = { .log = tap_log_fn, .log_priv = NULL }; + struct tdb_context tdb = { .logfn = tap_log_fn }; plan_tests(64 + 32 + 48*6 + 1); diff --git a/ccan/tdb2/test/run-seed.c b/ccan/tdb2/test/run-seed.c index 4f60cb5f..6abf5e9a 100644 --- a/ccan/tdb2/test/run-seed.c +++ b/ccan/tdb2/test/run-seed.c @@ -13,7 +13,7 @@ static int log_count = 0; /* Normally we get a log when setting random seed. */ static void my_log_fn(struct tdb_context *tdb, enum tdb_debug_level level, void *priv, - const char *fmt, ...) + const char *message) { log_count++; } diff --git a/ccan/tdb2/test/run-traverse.c b/ccan/tdb2/test/run-traverse.c index e3c2a895..e6d10285 100644 --- a/ccan/tdb2/test/run-traverse.c +++ b/ccan/tdb2/test/run-traverse.c @@ -120,7 +120,7 @@ int main(int argc, char *argv[]) hattr.base.next = &tap_log_attr; - plan_tests(sizeof(flags) / sizeof(flags[0]) * 50 + 1); + plan_tests(sizeof(flags) / sizeof(flags[0]) * 53 + 1); for (i = 0; i < sizeof(flags) / sizeof(flags[0]); i++) { tdb = tdb_open("run-traverse.tdb", flags[i], O_RDWR|O_CREAT|O_TRUNC, 0600, &hattr); @@ -182,6 +182,7 @@ int main(int argc, char *argv[]) ok1(td.low <= NUM_RECORDS / 2); ok1(td.high > NUM_RECORDS / 2); ok1(tdb_check(tdb, NULL, NULL) == 0); + ok1(tap_log_messages == 0); /* Growing traverse. Expect failure on r/o traverse. */ tgd.calls = 0; @@ -193,6 +194,8 @@ int main(int argc, char *argv[]) ok1(tgd.error == TDB_ERR_RDONLY); ok1(tgd.calls == 1); ok1(!tgd.mismatch); + ok1(tap_log_messages == 1); + tap_log_messages = 0; ok1(tdb_check(tdb, NULL, NULL) == 0); /* Deleting traverse. Expect failure on r/o traverse. */ @@ -209,6 +212,8 @@ int main(int argc, char *argv[]) ok1(!td.mismatch); ok1(td.calls == 1); ok1(td.low == td.high); + ok1(tap_log_messages == 1); + tap_log_messages = 0; ok1(tdb_check(tdb, NULL, NULL) == 0); /* Deleting traverse (delete everything). */ diff --git a/ccan/tdb2/transaction.c b/ccan/tdb2/transaction.c index 0aad8de8..92658026 100644 --- a/ccan/tdb2/transaction.c +++ b/ccan/tdb2/transaction.c @@ -169,10 +169,9 @@ static int transaction_read(struct tdb_context *tdb, tdb_off_t off, void *buf, return 0; fail: - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "transaction_read: failed at off=%llu len=%llu\n", - (long long)off, (long long)len); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "transaction_read: failed at off=%zu len=%zu", + (size_t)off, (size_t)len); tdb->transaction->transaction_error = 1; return -1; } @@ -188,12 +187,10 @@ static int transaction_write(struct tdb_context *tdb, tdb_off_t off, /* Only a commit is allowed on a prepared transaction */ if (tdb->transaction->prepared) { - tdb->ecode = TDB_ERR_EINVAL; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_FATAL, "transaction_write: transaction already prepared," - " write not allowed\n"); - tdb->transaction->transaction_error = 1; - return -1; + " write not allowed"); + goto fail; } /* break it up into block sized chunks */ @@ -228,7 +225,8 @@ static int transaction_write(struct tdb_context *tdb, tdb_off_t off, (blk+1)*sizeof(uint8_t *)); } if (new_blocks == NULL) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "transaction_write: failed to allocate"); goto fail; } memset(&new_blocks[tdb->transaction->num_blocks], 0, @@ -242,9 +240,9 @@ static int transaction_write(struct tdb_context *tdb, tdb_off_t off, if (tdb->transaction->blocks[blk] == NULL) { tdb->transaction->blocks[blk] = (uint8_t *)calloc(getpagesize(), 1); if (tdb->transaction->blocks[blk] == NULL) { - tdb->ecode = TDB_ERR_OOM; - tdb->transaction->transaction_error = 1; - return -1; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "transaction_write: failed to allocate"); + goto fail; } if (tdb->transaction->old_map_size > blk * getpagesize()) { tdb_len_t len2 = getpagesize(); @@ -254,6 +252,10 @@ static int transaction_write(struct tdb_context *tdb, tdb_off_t off, if (tdb->transaction->io_methods->read(tdb, blk * getpagesize(), tdb->transaction->blocks[blk], len2) != 0) { + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "transaction_write: failed to" + " read old block: %s", + strerror(errno)); SAFE_FREE(tdb->transaction->blocks[blk]); goto fail; } @@ -278,10 +280,6 @@ static int transaction_write(struct tdb_context *tdb, tdb_off_t off, return 0; fail: - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "transaction_write: failed at off=%llu len=%llu\n", - (long long)((blk*getpagesize()) + off), - (long long)len); tdb->transaction->transaction_error = 1; return -1; } @@ -341,6 +339,12 @@ static int transaction_oob(struct tdb_context *tdb, tdb_off_t len, bool probe) return 0; } tdb->ecode = TDB_ERR_IO; + if (!probe) { + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_oob len %lld beyond transaction size %lld", + (long long)len, + (long long)tdb->map_size); + } return -1; } @@ -383,9 +387,9 @@ static int transaction_sync(struct tdb_context *tdb, tdb_off_t offset, tdb_len_t } if (fsync(tdb->fd) != 0) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction: fsync failed\n"); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_transaction: fsync failed: %s", + strerror(errno)); return -1; } #ifdef MS_SYNC @@ -393,10 +397,9 @@ static int transaction_sync(struct tdb_context *tdb, tdb_off_t offset, tdb_len_t tdb_off_t moffset = offset & ~(getpagesize()-1); if (msync(moffset + (char *)tdb->map_ptr, length + (offset - moffset), MS_SYNC) != 0) { - tdb->ecode = TDB_ERR_IO; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction: msync failed - %s\n", - strerror(errno)); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_FATAL, + "tdb_transaction: msync failed: %s", + strerror(errno)); return -1; } } @@ -410,9 +413,8 @@ static void _tdb_transaction_cancel(struct tdb_context *tdb) int i; if (tdb->transaction == NULL) { - tdb->ecode = TDB_ERR_EINVAL; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_cancel: no transaction\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_cancel: no transaction"); return; } @@ -441,9 +443,9 @@ static void _tdb_transaction_cancel(struct tdb_context *tdb) &invalid, sizeof(invalid)) == -1 || transaction_sync(tdb, tdb->transaction->magic_offset, sizeof(invalid)) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_cancel: failed to remove" - " recovery magic\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_cancel: failed to remove" + " recovery magic"); } } @@ -469,16 +471,17 @@ int tdb_transaction_start(struct tdb_context *tdb) { /* some sanity checks */ if (tdb->read_only || (tdb->flags & TDB_INTERNAL)) { - tdb->ecode = TDB_ERR_EINVAL; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_start: cannot start a transaction" - " on a read-only or internal db\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_start: cannot start a transaction" + " on a read-only or internal db"); return -1; } /* cope with nested tdb_transaction_start() calls */ if (tdb->transaction != NULL) { - tdb->ecode = TDB_ERR_NESTING; + tdb_logerr(tdb, TDB_ERR_NESTING, TDB_DEBUG_ERROR, + "tdb_transaction_start:" + " already inside transaction"); return -1; } @@ -486,17 +489,17 @@ int tdb_transaction_start(struct tdb_context *tdb) /* the caller must not have any locks when starting a transaction as otherwise we'll be screwed by lack of nested locks in posix */ - tdb->ecode = TDB_ERR_LOCK; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_start: cannot start a transaction" - " with locks held\n"); + tdb_logerr(tdb, TDB_ERR_LOCK, TDB_DEBUG_ERROR, + "tdb_transaction_start: cannot start a transaction" + " with locks held"); return -1; } tdb->transaction = (struct tdb_transaction *) calloc(sizeof(struct tdb_transaction), 1); if (tdb->transaction == NULL) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_ERROR, + "tdb_transaction_start: cannot allocate"); return -1; } @@ -585,17 +588,17 @@ static int tdb_recovery_allocate(struct tdb_context *tdb, recovery_head = tdb_read_off(tdb, offsetof(struct tdb_header,recovery)); if (recovery_head == TDB_OFF_ERR) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_recovery_allocate:" - " failed to read recovery head\n"); + " failed to read recovery head"); return -1; } if (recovery_head != 0) { if (methods->read(tdb, recovery_head, &rec, sizeof(rec))) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_recovery_allocate:" - " failed to read recovery record\n"); + " failed to read recovery record"); return -1; } tdb_convert(tdb, &rec, sizeof(rec)); @@ -624,9 +627,9 @@ static int tdb_recovery_allocate(struct tdb_context *tdb, 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, - "tdb_recovery_allocate:" - " failed to free previous recovery area\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_recovery_allocate:" + " failed to free previous recovery area"); return -1; } } @@ -650,9 +653,9 @@ static int tdb_recovery_allocate(struct tdb_context *tdb, sizeof(rec) + *recovery_max_size; tdb->map_size = tdb->transaction->old_map_size; if (methods->expand_file(tdb, addition) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_recovery_allocate:" - " failed to create recovery area\n"); + " failed to create recovery area"); return -1; } @@ -666,9 +669,9 @@ static int tdb_recovery_allocate(struct tdb_context *tdb, tdb_convert(tdb, &recovery_head, sizeof(recovery_head)); if (methods->write(tdb, offsetof(struct tdb_header, recovery), &recovery_head, sizeof(tdb_off_t)) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_recovery_allocate:" - " failed to write recovery head\n"); + " failed to write recovery head"); return -1; } transaction_write_existing(tdb, offsetof(struct tdb_header, recovery), @@ -714,7 +717,8 @@ static int transaction_setup_recovery(struct tdb_context *tdb, data = (unsigned char *)malloc(recovery_size + sizeof(*rec)); if (data == NULL) { - tdb->ecode = TDB_ERR_OOM; + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "transaction_setup_recovery: cannot allocate"); return -1; } @@ -744,10 +748,9 @@ static int transaction_setup_recovery(struct tdb_context *tdb, continue; } if (offset + length > tdb->map_size) { - tdb->ecode = TDB_ERR_CORRUPT; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_setup_recovery:" - " transaction data over new region boundary\n"); + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "tdb_transaction_setup_recovery:" + " transaction data over new region boundary"); free(data); return -1; } @@ -775,9 +778,9 @@ static int transaction_setup_recovery(struct tdb_context *tdb, /* write the recovery data to the recovery area */ if (methods->write(tdb, recovery_offset, data, sizeof(*rec) + recovery_size) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_setup_recovery:" - " failed to write recovery data\n"); + " failed to write recovery data"); free(data); return -1; } @@ -802,9 +805,9 @@ static int transaction_setup_recovery(struct tdb_context *tdb, magic); if (methods->write(tdb, *magic_offset, &magic, sizeof(magic)) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_setup_recovery:" - " failed to write recovery magic\n"); + " failed to write recovery magic"); return -1; } transaction_write_existing(tdb, *magic_offset, &magic, sizeof(magic)); @@ -822,27 +825,24 @@ static int _tdb_transaction_prepare_commit(struct tdb_context *tdb) const struct tdb_methods *methods; if (tdb->transaction == NULL) { - tdb->ecode = TDB_ERR_EINVAL; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_prepare_commit: no transaction\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_prepare_commit: no transaction"); return -1; } if (tdb->transaction->prepared) { - tdb->ecode = TDB_ERR_EINVAL; _tdb_transaction_cancel(tdb); - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_prepare_commit:" - " transaction already prepared\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_prepare_commit:" + " transaction already prepared"); return -1; } if (tdb->transaction->transaction_error) { - tdb->ecode = TDB_ERR_IO; _tdb_transaction_cancel(tdb); - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_prepare_commit:" - " transaction error pending\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_prepare_commit:" + " transaction error pending"); return -1; } @@ -861,9 +861,9 @@ static int _tdb_transaction_prepare_commit(struct tdb_context *tdb) /* upgrade the main transaction lock region to a write lock */ if (tdb_allrecord_upgrade(tdb) == -1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_ERROR, "tdb_transaction_prepare_commit:" - " failed to upgrade hash locks\n"); + " failed to upgrade hash locks"); _tdb_transaction_cancel(tdb); return -1; } @@ -871,9 +871,9 @@ static int _tdb_transaction_prepare_commit(struct tdb_context *tdb) /* get the open lock - this prevents new users attaching to the database during the commit */ if (tdb_lock_open(tdb, TDB_LOCK_WAIT|TDB_LOCK_NOCHECK) == -1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_ERROR, "tdb_transaction_prepare_commit:" - " failed to get open lock\n"); + " failed to get open lock"); _tdb_transaction_cancel(tdb); return -1; } @@ -882,9 +882,9 @@ static int _tdb_transaction_prepare_commit(struct tdb_context *tdb) if (!(tdb->flags & TDB_NOSYNC)) { /* write the recovery data to the end of the file */ if (transaction_setup_recovery(tdb, &tdb->transaction->magic_offset) == -1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_prepare_commit:" - " failed to setup recovery data\n"); + " failed to setup recovery data"); _tdb_transaction_cancel(tdb); return -1; } @@ -898,9 +898,9 @@ static int _tdb_transaction_prepare_commit(struct tdb_context *tdb) /* Restore original map size for tdb_expand_file */ tdb->map_size = tdb->transaction->old_map_size; if (methods->expand_file(tdb, add) == -1) { - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_ERROR, "tdb_transaction_prepare_commit:" - " expansion failed\n"); + " expansion failed"); _tdb_transaction_cancel(tdb); return -1; } @@ -928,19 +928,18 @@ int tdb_transaction_commit(struct tdb_context *tdb) int i; if (tdb->transaction == NULL) { - tdb->ecode = TDB_ERR_EINVAL; - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_commit: no transaction\n"); + tdb_logerr(tdb, TDB_ERR_EINVAL, TDB_DEBUG_ERROR, + "tdb_transaction_commit: no transaction"); return -1; } tdb_trace(tdb, "tdb_transaction_commit"); if (tdb->transaction->transaction_error) { - tdb->ecode = TDB_ERR_IO; tdb_transaction_cancel(tdb); - tdb->log(tdb, TDB_DEBUG_ERROR, tdb->log_priv, - "tdb_transaction_commit: transaction error pending\n"); + tdb_logerr(tdb, TDB_ERR_IO, TDB_DEBUG_ERROR, + "tdb_transaction_commit:" + " transaction error pending"); return -1; } @@ -981,9 +980,9 @@ int tdb_transaction_commit(struct tdb_context *tdb) if (methods->write(tdb, offset, tdb->transaction->blocks[i], length) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_commit:" - " write failed during commit\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_commit:" + " write failed during commit"); /* we've overwritten part of the data and possibly expanded the file, so we need to @@ -1043,9 +1042,9 @@ int tdb_transaction_recover(struct tdb_context *tdb) /* find the recovery area */ recovery_head = tdb_read_off(tdb, offsetof(struct tdb_header,recovery)); if (recovery_head == TDB_OFF_ERR) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_recover:" - " failed to read recovery head\n"); + " failed to read recovery head"); return -1; } @@ -1056,9 +1055,9 @@ int tdb_transaction_recover(struct tdb_context *tdb) /* read the recovery record */ if (tdb_read_convert(tdb, recovery_head, &rec, sizeof(rec)) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover:" - " failed to read recovery record\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_recover:" + " failed to read recovery record"); return -1; } @@ -1068,10 +1067,9 @@ int tdb_transaction_recover(struct tdb_context *tdb) } if (tdb->read_only) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover:" - " attempt to recover read only database\n"); - tdb->ecode = TDB_ERR_CORRUPT; + tdb_logerr(tdb, TDB_ERR_CORRUPT, TDB_DEBUG_FATAL, + "tdb_transaction_recover:" + " attempt to recover read only database"); return -1; } @@ -1079,19 +1077,18 @@ int tdb_transaction_recover(struct tdb_context *tdb) data = (unsigned char *)malloc(rec.len); if (data == NULL) { - tdb->ecode = TDB_ERR_OOM; - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover:" - " failed to allocate recovery data\n"); + tdb_logerr(tdb, TDB_ERR_OOM, TDB_DEBUG_FATAL, + "tdb_transaction_recover:" + " failed to allocate recovery data"); return -1; } /* read the full recovery data */ if (tdb->methods->read(tdb, recovery_head + sizeof(rec), data, rec.len) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover:" - " failed to read recovery data\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_recover:" + " failed to read recovery data"); return -1; } @@ -1107,9 +1104,9 @@ int tdb_transaction_recover(struct tdb_context *tdb) if (tdb->methods->write(tdb, ofs, p, len) == -1) { free(data); - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_recover:" - " failed to recover %zu bytes at offset %zu\n", + " failed to recover %zu bytes at offset %zu", (size_t)len, (size_t)ofs); return -1; } @@ -1119,8 +1116,8 @@ int tdb_transaction_recover(struct tdb_context *tdb) free(data); if (transaction_sync(tdb, 0, tdb->map_size) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover: failed to sync recovery\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_recover: failed to sync recovery"); return -1; } @@ -1128,9 +1125,9 @@ int tdb_transaction_recover(struct tdb_context *tdb) if (recovery_eof <= recovery_head) { if (tdb_write_off(tdb, offsetof(struct tdb_header,recovery), 0) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_recover:" - " failed to remove recovery head\n"); + " failed to remove recovery head"); return -1; } } @@ -1140,21 +1137,21 @@ int tdb_transaction_recover(struct tdb_context *tdb) recovery_head + offsetof(struct tdb_recovery_record, magic), TDB_RECOVERY_INVALID_MAGIC) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, "tdb_transaction_recover:" - " failed to remove recovery magic\n"); + " failed to remove recovery magic"); return -1; } if (transaction_sync(tdb, 0, recovery_eof) == -1) { - tdb->log(tdb, TDB_DEBUG_FATAL, tdb->log_priv, - "tdb_transaction_recover: failed to sync2 recovery\n"); + tdb_logerr(tdb, tdb->ecode, TDB_DEBUG_FATAL, + "tdb_transaction_recover: failed to sync2 recovery"); return -1; } - tdb->log(tdb, TDB_DEBUG_TRACE, tdb->log_priv, - "tdb_transaction_recover: recovered %zu byte database\n", - (size_t)recovery_eof); + tdb_logerr(tdb, TDB_SUCCESS, TDB_DEBUG_TRACE, + "tdb_transaction_recover: recovered %zu byte database", + (size_t)recovery_eof); /* all done */ return 0;