test-hashmap: use the usual function headers and print timing stats

This makes it slightly easier to watch for performance changes.

2 files changed, 48 insertions, 32 deletions

diff --git a/src/test/test-hashmap-plain.c b/src/test/test-hashmap-plain.c
index c04ef0b1f..039c0e0e5 100644
--- a/src/test/test-hashmap-plain.c
+++ b/src/test/test-hashmap-plain.c
@@ -14,7 +14,7 @@ static void test_hashmap_replace(void) {
         Hashmap *m;
         char *val1, *val2, *val3, *val4, *val5, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
 
@@ -54,7 +54,7 @@ static void test_hashmap_copy(void) {
         Hashmap *m, *copy;
         char *val1, *val2, *val3, *val4, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("val1");
         assert_se(val1);
@@ -92,7 +92,7 @@ static void test_hashmap_get_strv(void) {
         char **strv;
         char *val1, *val2, *val3, *val4;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("val1");
         assert_se(val1);
@@ -130,7 +130,7 @@ static void test_hashmap_move_one(void) {
         Hashmap *m, *n;
         char *val1, *val2, *val3, *val4, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("val1");
         assert_se(val1);
@@ -171,7 +171,7 @@ static void test_hashmap_move(void) {
         Hashmap *m, *n;
         char *val1, *val2, *val3, *val4, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("val1");
         assert_se(val1);
@@ -215,7 +215,7 @@ static void test_hashmap_update(void) {
         Hashmap *m;
         char *val1, *val2, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         val1 = strdup("old_value");
@@ -247,7 +247,7 @@ static void test_hashmap_put(void) {
         void *val2 = (void*) "val 2";
         _cleanup_free_ char* key1 = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         assert_se(hashmap_ensure_allocated(&m, &string_hash_ops) >= 0);
         assert_se(m);
@@ -267,7 +267,7 @@ static void test_hashmap_remove(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
         char *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         r = hashmap_remove(NULL, "key 1");
         assert_se(r == NULL);
@@ -297,7 +297,7 @@ static void test_hashmap_remove2(void) {
         char val2[] = "val 2";
         void *r, *r2;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         r = hashmap_remove2(NULL, "key 1", &r2);
         assert_se(r == NULL);
@@ -329,7 +329,7 @@ static void test_hashmap_remove_value(void) {
         char val1[] = "val 1";
         char val2[] = "val 2";
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         r = hashmap_remove_value(NULL, "key 1", val1);
         assert_se(r == NULL);
@@ -363,7 +363,7 @@ static void test_hashmap_remove_and_put(void) {
         int valid;
         char *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -399,7 +399,7 @@ static void test_hashmap_remove_and_replace(void) {
         void *r;
         int i, j;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&trivial_hash_ops);
         assert_se(m);
@@ -452,7 +452,7 @@ static void test_hashmap_ensure_allocated(void) {
         Hashmap *m;
         int valid_hashmap;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
 
@@ -475,7 +475,7 @@ static void test_hashmap_foreach_key(void) {
                 "key 3\0"
                 "key 4\0";
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
 
@@ -507,7 +507,7 @@ static void test_hashmap_foreach(void) {
         char *val1, *val2, *val3, *val4, *s;
         unsigned count;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("my val1");
         assert_se(val1);
@@ -559,7 +559,7 @@ static void test_hashmap_merge(void) {
         Hashmap *n;
         char *val1, *val2, *val3, *val4, *r;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("my val1");
         assert_se(val1);
@@ -594,7 +594,7 @@ static void test_hashmap_contains(void) {
         Hashmap *m;
         char *val1;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("my val");
         assert_se(val1);
@@ -616,7 +616,7 @@ static void test_hashmap_isempty(void) {
         Hashmap *m;
         char *val1;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("my val");
         assert_se(val1);
@@ -635,7 +635,7 @@ static void test_hashmap_size(void) {
         Hashmap *m;
         char *val1, *val2, *val3, *val4;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val1 = strdup("my val");
         assert_se(val1);
@@ -667,7 +667,7 @@ static void test_hashmap_get(void) {
         char *r;
         char *val;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val = strdup("my val");
         assert_se(val);
@@ -696,7 +696,7 @@ static void test_hashmap_get2(void) {
         char key_orig[] = "Key 1";
         void *key_copy;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         val = strdup("my val");
         assert_se(val);
@@ -739,16 +739,20 @@ static void test_hashmap_many(void) {
         void *v, *k;
         bool slow = slow_tests_enabled();
         const struct {
+                const char *title;
                 const struct hash_ops *ops;
                 unsigned n_entries;
         } tests[] = {
-                { .ops = NULL,                  .n_entries = slow ? 1 << 20 : 240 },
-                { .ops = &crippled_hashmap_ops, .n_entries = slow ? 1 << 14 : 140 },
+                { "trivial_hashmap_ops",  NULL,                  slow ? 1 << 20 : 240 },
+                { "crippled_hashmap_ops", &crippled_hashmap_ops, slow ? 1 << 14 : 140 },
         };
 
-        log_info("%s (%s)", __func__, slow ? "slow" : "fast");
+        log_info("/* %s (%s) */", __func__, slow ? "slow" : "fast");
 
         for (j = 0; j < ELEMENTSOF(tests); j++) {
+                usec_t ts = now(CLOCK_MONOTONIC), n;
+                char b[FORMAT_TIMESPAN_MAX];
+
                 assert_se(h = hashmap_new(tests[j].ops));
 
                 for (i = 1; i < tests[j].n_entries*3; i+=3) {
@@ -759,7 +763,8 @@ static void test_hashmap_many(void) {
                 for (i = 1; i < tests[j].n_entries*3; i++)
                         assert_se(hashmap_contains(h, UINT_TO_PTR(i)) == (i % 3 == 1));
 
-                log_info("%u <= %u * 0.8 = %g", hashmap_size(h), hashmap_buckets(h), hashmap_buckets(h) * 0.8);
+                log_info("%s %u <= %u * 0.8 = %g",
+                         tests[j].title, hashmap_size(h), hashmap_buckets(h), hashmap_buckets(h) * 0.8);
 
                 assert_se(hashmap_size(h) <= hashmap_buckets(h) * 0.8);
                 assert_se(hashmap_size(h) == tests[j].n_entries);
@@ -771,13 +776,16 @@ static void test_hashmap_many(void) {
                 }
 
                 hashmap_free(h);
+
+                n = now(CLOCK_MONOTONIC);
+                log_info("test took %s", format_timespan(b, sizeof b, n - ts, 0));
         }
 }
 
 static void test_hashmap_first(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -796,7 +804,7 @@ static void test_hashmap_first(void) {
 static void test_hashmap_first_key(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -815,7 +823,7 @@ static void test_hashmap_first_key(void) {
 static void test_hashmap_steal_first_key(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -832,7 +840,7 @@ static void test_hashmap_steal_first(void) {
         int seen[3] = {};
         char *val;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -852,7 +860,7 @@ static void test_hashmap_steal_first(void) {
 static void test_hashmap_clear_free_free(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
         assert_se(m);
@@ -878,7 +886,7 @@ DEFINE_PRIVATE_HASH_OPS_FULL(test_hash_ops_full, char, string_hash_func, string_
 static void test_hashmap_clear_free_with_destructor(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&test_hash_ops_key);
         assert_se(m);
@@ -905,7 +913,7 @@ static void test_hashmap_clear_free_with_destructor(void) {
 static void test_hashmap_reserve(void) {
         _cleanup_hashmap_free_ Hashmap *m = NULL;
 
-        log_info("%s", __func__);
+        log_info("/* %s */", __func__);
 
         m = hashmap_new(&string_hash_ops);
 
diff --git a/src/test/test-hashmap.c b/src/test/test-hashmap.c
index d525ba770..6f29266d6 100644
--- a/src/test/test-hashmap.c
+++ b/src/test/test-hashmap.c
@@ -10,6 +10,8 @@ static void test_ordered_hashmap_next(void) {
         _cleanup_ordered_hashmap_free_ OrderedHashmap *m = NULL;
         int i;
 
+        log_info("/* %s */", __func__);
+
         assert_se(m = ordered_hashmap_new(NULL));
         for (i = -2; i <= 2; i++)
                 assert_se(ordered_hashmap_put(m, INT_TO_PTR(i), INT_TO_PTR(i+10)) == 1);
@@ -32,6 +34,8 @@ static void test_hashmap_free_with_destructor(void) {
         struct Item items[4] = {};
         unsigned i;
 
+        log_info("/* %s */", __func__);
+
         assert_se(m = hashmap_new(NULL));
         for (i = 0; i < ELEMENTSOF(items) - 1; i++)
                 assert_se(hashmap_put(m, INT_TO_PTR(i), items + i) == 1);
@@ -87,6 +91,8 @@ static void test_iterated_cache(void) {
         Hashmap *m;
         IteratedCache *c;
 
+        log_info("/* %s */", __func__);
+
         assert_se(m = hashmap_new(NULL));
         assert_se(c = hashmap_iterated_cache_new(m));
         compare_cache(m, c);
@@ -122,6 +128,8 @@ static void test_iterated_cache(void) {
 static void test_path_hashmap(void) {
         _cleanup_hashmap_free_ Hashmap *h = NULL;
 
+        log_info("/* %s */", __func__);
+
         assert_se(h = hashmap_new(&path_hash_ops));
 
         assert_se(hashmap_put(h, "foo", INT_TO_PTR(1)) >= 0);