From: Petr Špaček <petr.spacek@nic.cz>
Date: Fri, 4 Sep 2020 17:19:18 +0000 (+0200)
Subject: lib/cache: improve debugging prints
X-Git-Tag: v5.1.3~1^2~5
X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=45e90fb9c4fa5d3e6bc8940c095682a06b2643e7;p=thirdparty%2Fknot-resolver.git

lib/cache: improve debugging prints

(This has shared authorship, basically, mostly from MR suggestions.)
---

diff --git a/lib/cache/api.c b/lib/cache/api.c
index 1a9781bf1..3e8351fad 100644
--- a/lib/cache/api.c
+++ b/lib/cache/api.c
@@ -80,15 +80,16 @@ static int assert_right_version(struct kr_cache *cache)
 		/* Version doesn't match. Recreate cache and write version key. */
 		ret = cache_op(cache, count);
 		if (ret != 0) { /* Non-empty cache, purge it. */
-			kr_log_info("[     ][cach] incompatible cache database detected, purging\n");
+			kr_log_info("[cache] incompatible cache database detected, purging\n");
 			if (oldret) {
-				kr_log_verbose("bad ret: %d\n", oldret);
+				kr_log_verbose("[cache] reading version returned: %d\n", oldret);
 			} else if (val.len != sizeof(CACHE_VERSION)) {
-				kr_log_verbose("bad length: %d\n", (int)val.len);
+				kr_log_verbose("[cache] version has bad length: %d\n", (int)val.len);
 			} else {
 				uint16_t ver;
 				memcpy(&ver, val.data, sizeof(ver));
-				kr_log_verbose("bad version: %d\n", (int)ver);
+				kr_log_verbose("[cache] version has bad value: %d instead of %d\n",
+					(int)ver, (int)CACHE_VERSION);
 			}
 			ret = cache_op(cache, clear);
 		}
@@ -133,12 +134,21 @@ int kr_cache_open(struct kr_cache *cache, const struct kr_cdb_api *api, struct k
 		opts2.maxsize = 0;
 		ret = cache->api->open(&cache->db, &cache->stats, &opts2, mm);
 	}
+
+	char *fpath;
+	if (asprintf(&fpath, "%s/data.mdb", opts->path) > 0) {
+		kr_cache_emergency_file_to_remove = fpath;
+	} else {
+		assert(false); /* non-critical, but still */
+		fpath = "<ENOMEM>";
+	}
+
 	if (ret == 0 && opts->maxsize) {
 		size_t maxsize = cache->api->get_maxsize(cache->db);
 		if (maxsize > opts->maxsize) kr_log_info(
-			"[cache] Warning: cache size %zu instead of %zu."
-			"  To reduce the size you need to remove the file by hand.\n",
-			maxsize, opts->maxsize);
+			"[cache] Warning: real cache size is %zu instead of the requested %zu bytes."
+			"  To reduce the size you need to remove the file '%s' by hand.\n",
+			maxsize, opts->maxsize, fpath);
 	}
 	if (ret != 0) {
 		return ret;
@@ -146,14 +156,6 @@ int kr_cache_open(struct kr_cache *cache, const struct kr_cdb_api *api, struct k
 	cache->ttl_min = KR_CACHE_DEFAULT_TTL_MIN;
 	cache->ttl_max = KR_CACHE_DEFAULT_TTL_MAX;
 	kr_cache_make_checkpoint(cache);
-
-	char *fpath;
-	ret = asprintf(&fpath, "%s/data.mdb", opts->path);
-	if (ret > 0) {
-		kr_cache_emergency_file_to_remove = fpath;
-	} else {
-		assert(false); /* non-critical, but still */
-	}
 	return 0;
 }
 
diff --git a/lib/cache/cdb_lmdb.c b/lib/cache/cdb_lmdb.c
index 685f2e215..3b986df82 100644
--- a/lib/cache/cdb_lmdb.c
+++ b/lib/cache/cdb_lmdb.c
@@ -104,8 +104,9 @@ static int refresh_mapsize(struct lmdb_env *env)
 
 	env->mapsize = info.me_mapsize;
 	if (env->mapsize != env->st_size) {
-		kr_log_info("[cache] suspicious size of cache file: %zu != %zu\n",
-				(size_t)env->st_size, env->mapsize);
+		kr_log_info("[cache] suspicious size of cache file '%s'"
+				": file size %zu != LMDB map size %zu\n",
+				env->mdb_data_path, (size_t)env->st_size, env->mapsize);
 	}
 	return kr_ok();
 }
@@ -481,8 +482,9 @@ static int cdb_check_health(knot_db_t *db, struct kr_cdb_stats *stats)
 	 * contrary to methods based on mdb_env_info(). */
 	if (st.st_size == env->st_size)
 		return kr_ok();
-	kr_log_info("[cache] detected file size change by another process: %zu -> %zu\n",
-			(size_t)env->st_size, (size_t)st.st_size);
+	kr_log_info("[cache] detected size change (by another instance?) of file '%s'"
+			": file size %zu -> file size %zu\n",
+			env->mdb_data_path, (size_t)env->st_size, (size_t)st.st_size);
 	env->st_size = st.st_size; // avoid retrying in cycle even if we fail
 	return refresh_mapsize(env);
 }
diff --git a/lib/cache/entry_list.c b/lib/cache/entry_list.c
index 39c57dae5..7110135bc 100644
--- a/lib/cache/entry_list.c
+++ b/lib/cache/entry_list.c
@@ -179,7 +179,7 @@ static int cache_write_or_clear(struct kr_cache *cache, const knot_db_val_t *key
 	ret = kr_cache_clear(cache);
 	switch (ret) {
 	default:
-		kr_log_error("CRITICAL: clearing cache failed with %s\n",
+		kr_log_error("CRITICAL: clearing cache failed: %s; fatal error, aborting\n",
 				kr_strerror(ret));
 		abort();
 	case 0: