[committed] Print off_htab statistics with --devel-trace

[committed] Print off_htab statistics with --devel-trace

[Tom de Vries]

Hi,

Now that we try to be smart about off_htab allocation, and have changed the
hashing function, it's good to have easily accessible information about the
off_htab statistics.

Add printing of off_htab statistics at allocation, after parsing and before
deletion with --devel-trace:
...
$ cp cc1 1; time.sh dwz 1 -lnone --devel-trace
Compressing 1
htab: off_htab allocation
      size: 16777213
htab: off_htab post-parsing
      size: 16777213
      elements: 10188941, occupancy: 0.607308
      searches: 27075041, collisions: 0.207744
htab: off_htab final
      size: 16777213
      elements: 10188941, occupancy: 0.607308
      searches: 34256212, collisions: 0.206357
maxmem: 1177788
real: 5.97
user: 5.66
system: 0.30
...

In contrast, for a low-mem run we get:
...
$ cp cc1 1; time.sh dwz 1 -l0 --devel-trace
Compressing 1 in low-mem mode
htab: off_htab allocation
      size: 131071
htab: off_htab post-parsing
      size: 16777213
      elements (incl. deleted): 6536209, occupancy: 0.389588
      elements (excl. deleted): 1760770, occupancy: 0.104950
      searches: 47219770, collisions: 0.134397
htab: off_htab final
      size: 16777213
      elements (incl. deleted): 6536209, occupancy: 0.389588
      elements (excl. deleted): 1760770, occupancy: 0.104950
      searches: 75171859, collisions: 0.310610
maxmem: 655884
real: 9.85
user: 9.58
system: 0.27
...

It's easy to note that:
- in low-mem mode, we start with out with a small size and grow, while in
  regular mode we start out with a large size and don't grow
- in low-mem mode, we end up with fewer elements (6.5 instead of 10.2 million,
  and even 1.8 million if we don't count deleted elements)
- in low-mem mode, we end up with more searches (75.2 instead of 34.3 million).

Also, it's interesting to note that:
- collision rate goes up after parsing in low-mem mode (13% to 31%), but
  stays stable (at 21%) in regular mode.
- we end up with a higher collision rate in low-mem mode (31% instead of 21%),
  at a lower occupancy rate (38% instead of 61%).

Committed to trunk.

Thanks,
- Tom

Print off_htab statistics with --devel-trace

2019-11-26  Tom de Vries  <tdevries@suse.de>

	* dwz.c (htab_report): New function.
	(off_htab_add_die, read_debug_info, cleanup): Call htab_report to
	report on off_htab.

---
 dwz.c | 42 +++++++++++++++++++++++++++++++++++++++++-
 1 file changed, 41 insertions(+), 1 deletion(-)

diff --git a/dwz.c b/dwz.c
index 095af49..d5e477b 100644
--- a/dwz.c
+++ b/dwz.c
@@ -1227,6 +1227,38 @@ emulate_htab (size_t initial, size_t final_nr_elements)
   return size;
 }
 
+/* Print hash table statistics for hash table HTAB with message string MSG.  */
+static void
+htab_report (htab_t htab, const char *msg)
+{
+  double collisions = htab_collisions (htab);
+  unsigned int searches = htab->searches;
+  size_t elements = htab->n_elements;
+  size_t deleted = htab->n_deleted;
+  size_t adjusted_elements = elements - deleted;
+  size_t size = htab->size;
+  double occupancy = (double)elements / (double)size;
+  double adjusted_occupancy = (double)adjusted_elements / (double)size;
+  /* Indent unconditional fprintfs similar to conditional fprintfs to
+     left-align literal strings.  */
+  if (1)
+    fprintf (stderr, "htab: %s\n", msg);
+  if (1)
+    fprintf (stderr, "      size: %lu\n", size);
+  if (elements > 0 && deleted == 0)
+    fprintf (stderr, "      elements: %lu, occupancy: %f\n", elements,
+	     occupancy);
+  if (deleted > 0)
+    fprintf (stderr, "      elements (incl. deleted): %lu, occupancy: %f\n",
+	     elements, occupancy);
+  if (deleted > 0)
+    fprintf (stderr, "      elements (excl. deleted): %lu, occupancy: %f\n",
+	     adjusted_elements, adjusted_occupancy);
+  if (elements > 0)
+    fprintf (stderr, "      searches: %u, collisions: %f\n", searches,
+	     collisions);
+}
+
 /* Hash function for off_htab hash table.  */
 static hashval_t
 off_hash (const void *p)
@@ -1300,6 +1332,8 @@ off_htab_add_die (dw_cu_ref cu, dw_die_ref die, unsigned int *die_count)
 	  initial_size = final_hashtab_size;
 	}
       off_htab = htab_try_create (initial_size, off_hash, off_eq, NULL);
+      if (tracing)
+	htab_report (off_htab, "off_htab allocation");
       if (off_htab == NULL)
 	dwz_oom ();
       if (rd_multifile)
@@ -5674,6 +5708,8 @@ read_debug_info (DSO *dso, int kind, unsigned int *die_count)
       return 0;
     }
 
+  if (tracing)
+    htab_report (off_htab, "off_htab post-parsing");
   if (die_count)
     *die_count = ndies;
   htab_delete (dup_htab);
@@ -11245,7 +11281,11 @@ cleanup (void)
       cu->cu_new_abbrev = NULL;
     }
   if (off_htab != NULL)
-    htab_delete (off_htab);
+    {
+      if (tracing)
+	htab_report (off_htab, "off_htab final");
+      htab_delete (off_htab);
+    }
   off_htab = NULL;
   if (types_off_htab != NULL)
     htab_delete (types_off_htab);