(#511) Add fns to print 'size' as human-readable string w/ unit-speci…

…fiers

This commit adds couple of utility functions to snprintf(), in an output
buffer, the 'size' unit to a human-readable string with unit-specifiers.

- size_to_str() - Convert 'size' to a string in an output buffer
- size_to_fmtstr() - Same as above, using user-specified format-string.
   Useful to generate output enclosed in, e.g., '(%s)'.
- Add size_str(), size_fmstr() caller-macros to simplify calling these
  formatting functions. These macros declare on-stack buffers used to
  format the output string. size_str() provided by Rob Johnson, to greatly
  simplify the usage.

Add utility bytes-to-Units conversion macros. Add unit tests to exercise
these interfaces. Apply these utility fns in couple of stats-printing
and BTree print-methods, to display size values as human-friendly unit
specifiers.

src/btree.c

@@ -3083,6 +3083,10 @@ btree_print_offset_table(platform_log_handle *log_handle, btree_hdr *hdr)
    platform_log(log_handle, "\n");
 }
 
+// Macro to deal with printing Pivot stats 'sz' bytes as uninitialized
+#define PIVOT_STATS_BYTES_AS_STR(sz)                                           \
+   (((sz) == BTREE_UNKNOWN_COUNTER) ? "BTREE_UNKNOWN_COUNTER" : size_str((sz)))
+
 static void
 btree_print_btree_pivot_stats(platform_log_handle *log_handle,
                               btree_pivot_stats   *pivot_stats)
@@ -3099,11 +3103,13 @@ btree_print_btree_pivot_stats(platform_log_handle *log_handle,
    // Indentation is dictated by outer caller
    platform_log(log_handle,
                 "   (num_kvs=%u\n"
-                "    key_bytes=%u\n"
-                "    message_bytes=%u)\n",
+                "    key_bytes=%u (%s)\n"
+                "    message_bytes=%u (%s))\n",
                 pivot_stats->num_kvs,
                 pivot_stats->key_bytes,
-                pivot_stats->message_bytes);
+                PIVOT_STATS_BYTES_AS_STR(pivot_stats->key_bytes),
+                pivot_stats->message_bytes,
+                PIVOT_STATS_BYTES_AS_STR(pivot_stats->message_bytes));
 }
 
 static void
@@ -3255,6 +3261,7 @@ btree_print_subtree(platform_log_handle *log_handle,
    node.addr = addr;
    btree_print_node(log_handle, cc, cfg, &node);
    if (!allocator_page_valid(cache_get_allocator(cc), node.addr)) {
+      platform_log(log_handle, "Unallocated BTree node addr=%lu\n", addr);
       return;
    }
    btree_node_get(cc, cfg, &node, PAGE_TYPE_BRANCH);

src/platform_linux/platform.h

@@ -88,14 +88,27 @@
 
 // Data unit constants
 #define KiB (1024UL)
-#define MiB (KiB * KiB)
-#define GiB (MiB * KiB)
+#define MiB (KiB * 1024)
+#define GiB (MiB * 1024)
+#define TiB (GiB * 1024)
 
+// Convert 'x' in unit-specifiers to bytes
 #define KiB_TO_B(x) ((x)*KiB)
 #define MiB_TO_B(x) ((x)*MiB)
 #define GiB_TO_B(x) ((x)*GiB)
+#define TiB_TO_B(x) ((x)*TiB)
+
+// Convert 'x' in bytes to 'int'-value with unit-specifiers
+#define B_TO_KiB(x) ((x) / KiB)
 #define B_TO_MiB(x) ((x) / MiB)
 #define B_TO_GiB(x) ((x) / GiB)
+#define B_TO_TiB(x) ((x) / TiB)
+
+// For x bytes, returns as int the fractional portion modulo a unit-specifier
+#define B_TO_KiB_FRACT(x) ((100 * ((x) % KiB)) / KiB)
+#define B_TO_MiB_FRACT(x) ((100 * ((x) % MiB)) / MiB)
+#define B_TO_GiB_FRACT(x) ((100 * ((x) % GiB)) / GiB)
+#define B_TO_TiB_FRACT(x) ((100 * ((x) % TiB)) / TiB)
 
 // Time unit constants
 #define THOUSAND (1000UL)

src/rc_allocator.c

@@ -777,50 +777,52 @@ rc_allocator_assert_noleaks(rc_allocator *al)
 void
 rc_allocator_print_stats(rc_allocator *al)
 {
-   int64 divider = GiB / al->cfg->io_cfg->extent_size;
+   // clang-format off
+   const char *dashes = "-------------------------------------------------------------------";
+   platform_default_log("|%s|\n", dashes);
+   platform_default_log("| Allocator Stats                                                   |\n");
+   platform_default_log("|%s|\n", dashes);
+   // clang-format on
+
+   uint64 extent_size = al->cfg->io_cfg->extent_size; // bytes
    platform_default_log(
-      "----------------------------------------------------------------\n");
-   platform_default_log(
-      "| Allocator Stats                                              |\n");
-   platform_default_log(
-      "|--------------------------------------------------------------|\n");
-   uint64 curr_gib = al->stats.curr_allocated / divider;
-   platform_default_log(
-      "| Currently Allocated: %12lu extents (%4luGiB)          |\n",
+      "| Currently Allocated: %12lu extents %-14s          |\n",
       al->stats.curr_allocated,
-      curr_gib);
-   uint64 max_gib = al->stats.max_allocated / divider;
+      size_fmtstr("(%s)", (al->stats.curr_allocated * extent_size)));
+
    platform_default_log(
-      "| Max Allocated:       %12lu extents (%4luGiB)          |\n",
+      "| Max Allocated:       %12lu extents %-14s          |\n",
       al->stats.max_allocated,
-      max_gib);
-   platform_default_log(
-      "|--------------------------------------------------------------|\n");
-   platform_default_log(
-      "| Page Type | Allocations | Deallocations | Footprint (bytes)  |\n");
-   platform_default_log(
-      "|--------------------------------------------------------------|\n");
+      size_fmtstr("(%s)", (al->stats.max_allocated * extent_size)));
+
+   // clang-format off
+   platform_default_log("|%s|\n", dashes);
+   platform_default_log("| Page Type  | Allocations | Deallocations |      Footprint         |\n");
+   platform_default_log("|            |      (Number of extents)    | # extents  (bytes)     |\n");
+   platform_default_log("|%s|\n", dashes);
+   // clang-format on
+
    int64 exp_allocated_count = 0;
    for (page_type type = PAGE_TYPE_FIRST; type < NUM_PAGE_TYPES; type++) {
-      const char *str           = page_type_str[type];
-      int64       allocs        = al->stats.extent_allocs[type];
-      int64       deallocs      = al->stats.extent_deallocs[type];
-      int64       footprint     = allocs - deallocs;
-      int64       footprint_gib = footprint / divider;
+      const char *str       = page_type_str[type];
+      int64       allocs    = al->stats.extent_allocs[type];
+      int64       deallocs  = al->stats.extent_deallocs[type];
+      int64       footprint = allocs - deallocs;
 
       exp_allocated_count += footprint;
 
-      platform_default_log("| %-10s | %11ld | %13ld | %8ld (%4ldGiB) |\n",
+      platform_default_log("| %-10s | %11ld | %13ld | %8ld %14s|\n",
                            str,
                            allocs,
                            deallocs,
                            footprint,
-                           footprint_gib);
+                           size_fmtstr("(%s)", (footprint * extent_size)));
    }
+   platform_default_log("|%s|\n", dashes);
    platform_default_log(
-      "----------------------------------------------------------------\n");
-   platform_default_log("Expected allocation count from footprint = %ld\n",
-                        exp_allocated_count);
+      "Expected count of extents in-use from footprint = %ld extents (%s)\n",
+      exp_allocated_count,
+      size_str(exp_allocated_count * extent_size));
 }
 
 /*
@@ -846,17 +848,20 @@ rc_allocator_print_allocated(rc_allocator *al)
    platform_default_log("   Index  ExtentAddr  Count\n");
 
    // # of extents with non-zero referenced page-count found
-   uint64 found = 0;
+   uint64 nextents_found = 0;
+   uint64 extent_size    = al->cfg->io_cfg->extent_size;
 
    for (i = 0; i < al->cfg->extent_capacity; i++) {
       ref = al->ref_count[i];
       if (ref != 0) {
-         found++;
-         uint64 ext_addr = (i * al->cfg->io_cfg->extent_size);
+         nextents_found++;
+         uint64 ext_addr = (i * extent_size);
          platform_default_log("%8lu %12lu     %u\n", i, ext_addr, ref);
       }
    }
-   platform_default_log("%sFound %lu extents with allocated pages.\n",
+
+   platform_default_log("%sFound %lu extents (%s) with allocated pages.\n",
                         (print_curly ? "}\n" : ""),
-                        found);
+                        nextents_found,
+                        size_str(nextents_found * extent_size));
 }

src/rc_allocator.h

@@ -44,8 +44,8 @@ _Static_assert(offsetof(rc_allocator_meta_page, splinters) == 0,
  *----------------------------------------------------------------------
  */
 typedef struct rc_allocator_stats {
-   int64 curr_allocated;
-   int64 max_allocated;
+   int64 curr_allocated; // # of extents allocated
+   int64 max_allocated;  // # of extents allocated high-water mark
    int64 extent_allocs[NUM_PAGE_TYPES];
    int64 extent_deallocs[NUM_PAGE_TYPES];
 } rc_allocator_stats;

src/trunk.c

@@ -7905,8 +7905,11 @@ trunk_print_space_use(platform_log_handle *log_handle, trunk_handle *spl)
                 "Space used by level: trunk_tree_height=%d\n",
                 trunk_tree_height(spl));
    for (uint16 i = 0; i <= trunk_tree_height(spl); i++) {
-      platform_log(
-         log_handle, "%u: %8lu MiB\n", i, B_TO_MiB(bytes_used_by_level[i]));
+      platform_log(log_handle,
+                   "%u: %lu bytes (%s)\n",
+                   i,
+                   bytes_used_by_level[i],
+                   size_str(bytes_used_by_level[i]));
    }
    platform_log(log_handle, "\n");
 }
@@ -8851,7 +8854,7 @@ trunk_node_print_branches(trunk_handle *spl, uint64 addr, void *arg)
          spl, &node, branch_no, &num_tuples_in_branch, &kv_bytes_in_branch);
       uint64 kib_in_branch = 0;
       // trunk_branch_extent_count(spl, &node, branch_no);
-      kib_in_branch *= trunk_extent_size(&spl->cfg) / 1024;
+      kib_in_branch *= B_TO_KiB(trunk_extent_size(&spl->cfg));
       fraction space_amp =
          init_fraction(kib_in_branch * 1024, kv_bytes_in_branch);
       platform_log(
@@ -8861,7 +8864,7 @@ trunk_node_print_branches(trunk_handle *spl, uint64 addr, void *arg)
          branch_no,
          addr,
          num_tuples_in_branch,
-         kv_bytes_in_branch / 1024,
+         B_TO_KiB(kv_bytes_in_branch),
          kib_in_branch,
          FRACTION_ARGS(space_amp));
    }

src/util.c

@@ -364,3 +364,64 @@ debug_hex_dump_slice(platform_log_handle *plh, uint64 grouping, slice data)
 {
    debug_hex_dump(plh, grouping, slice_length(data), slice_data(data));
 }
+
+/*
+ * Format a size value with unit-specifiers, in an output buffer.
+ * Returns 'outbuf', as ptr to size-value snprintf()'ed as a string.
+ */
+char *
+size_to_str(char *outbuf, size_t outbuflen, size_t size)
+{
+   debug_assert(outbuflen >= SIZE_TO_STR_LEN, "outbuflen=%lu.\n", outbuflen);
+   size_t unit_val  = 0;
+   size_t frac_val  = 0;
+   bool   is_approx = FALSE;
+
+   char *units = NULL;
+   if (size >= TiB) {
+      unit_val  = B_TO_TiB(size);
+      frac_val  = B_TO_TiB_FRACT(size);
+      is_approx = (size > TiB_TO_B(unit_val));
+      units     = "TiB";
+
+   } else if (size >= GiB) {
+      unit_val  = B_TO_GiB(size);
+      frac_val  = B_TO_GiB_FRACT(size);
+      is_approx = (size > GiB_TO_B(unit_val));
+      units     = "GiB";
+
+   } else if (size >= MiB) {
+      unit_val  = B_TO_MiB(size);
+      frac_val  = B_TO_MiB_FRACT(size);
+      is_approx = (size > MiB_TO_B(unit_val));
+      units     = "MiB";
+
+   } else if (size >= KiB) {
+      unit_val  = B_TO_KiB(size);
+      frac_val  = B_TO_KiB_FRACT(size);
+      is_approx = (size > KiB_TO_B(unit_val));
+      units     = "KiB";
+   } else {
+      unit_val = size;
+      units    = "bytes";
+   }
+
+   if (frac_val || is_approx) {
+      snprintf(outbuf, outbuflen, "~%ld.%ld %s", unit_val, frac_val, units);
+   } else {
+      snprintf(outbuf, outbuflen, "%ld %s", unit_val, units);
+   }
+   return outbuf;
+}
+
+/*
+ * Sibling of size_to_str(), but uses user-provided print format specifier.
+ * 'fmtstr' is expected to have just one '%s', and whatever other text user
+ * wishes to print with the output string.
+ */
+char *
+size_to_fmtstr(char *outbuf, size_t outbuflen, const char *fmtstr, size_t size)
+{
+   snprintf(outbuf, outbuflen, fmtstr, size_str(size));
+   return outbuf;
+}

src/util.h

@@ -382,4 +382,40 @@ debug_hex_dump_slice(platform_log_handle *, uint64 grouping, slice data);
     : ((intval) < 1000) ? "3d"                                                 \
                         : "4d")
 
+// Length of output buffer to snprintf()-into size as string w/ unit specifier
+#define SIZE_TO_STR_LEN 20
+
+// Format a size value with unit-specifiers, in an output buffer.
+char *
+size_to_str(char *outbuf, size_t outbuflen, size_t size);
+
+char *
+size_to_fmtstr(char *outbuf, size_t outbuflen, const char *fmtstr, size_t size);
+
+/*
+ * Convenience caller macros to convert 'sz' bytes to return a string,
+ * formatting the input size as human-readable value with unit-specifiers.
+ */
+// char *size_str(size_t sz)
+#define size_str(sz)                                                           \
+   (({                                                                         \
+       struct {                                                                \
+          char buffer[SIZE_TO_STR_LEN];                                        \
+       } onstack_chartmp;                                                      \
+       size_to_str(                                                            \
+          onstack_chartmp.buffer, sizeof(onstack_chartmp.buffer), sz);         \
+       onstack_chartmp;                                                        \
+    }).buffer)
+
+// char *size_fmtstr(const char *fmtstr, size_t sz)
+#define size_fmtstr(fmtstr, sz)                                                \
+   (({                                                                         \
+       struct {                                                                \
+          char buffer[SIZE_TO_STR_LEN];                                        \
+       } onstack_chartmp;                                                      \
+       size_to_fmtstr(                                                         \
+          onstack_chartmp.buffer, sizeof(onstack_chartmp.buffer), fmtstr, sz); \
+       onstack_chartmp;                                                        \
+    }).buffer)
+
 #endif // _SPLINTER_UTIL_H_

tests/unit/btree_stress_test.c

@@ -113,6 +113,16 @@ CTEST_DATA(btree_stress)
 // Setup function for suite, called before every test in suite
 CTEST_SETUP(btree_stress)
 {
+   if (Ctest_verbose) {
+      platform_set_log_streams(stdout, stderr);
+      CTEST_LOG_INFO("\nVerbose mode on.  This test exercises an error case, "
+                     "so on sucess it "
+                     "will print a message that appears to be an error.\n");
+   } else {
+      FILE *dev_null = fopen("/dev/null", "w");
+      ASSERT_NOT_NULL(dev_null);
+      platform_set_log_streams(dev_null, dev_null);
+   }
    config_set_defaults(&data->master_cfg);
    data->master_cfg.cache_capacity = GiB_TO_B(5);
    data->data_cfg                  = test_data_config;
@@ -256,6 +266,12 @@ CTEST2(btree_stress, test_random_inserts_concurrent)
       (cache *)&data->cc, &data->dbtree_cfg, packed_root_addr, nkvs, data->hid);
    ASSERT_NOT_EQUAL(0, rc, "Invalid ranges in packed tree\n");
 
+   // Exercise print method to verify that it basically continues to work.
+   btree_print_tree(Platform_default_log_handle,
+                    (cache *)&data->cc,
+                    &data->dbtree_cfg,
+                    packed_root_addr);
+
    // Release memory allocated in this test case
    for (uint64 i = 0; i < nthreads; i++) {
       platform_free(data->hid, params[i].scratch);