analyzer: improvements to logging/dumping

This patch adds various information to -fdump-analyzer and
-fdump-analyzer-stderr to make it easier to track down
problems with state explosions in the exploded_graph.

It logs the number of unprocessed nodes in the worklist, for
the case where the upper limit on exploded nodes is reached.

It prints:
[a] a bar chart showing the number of exploded nodes by function, and

[b] bar charts for each function showing the number of exploded nodes
    per supernode/BB, and

[c] bar charts for each function showing the number of excess exploded
    nodes per supernode/BB beyond the limit
    (--param=analyzer-max-enodes-per-program-point), where that limit
    was reached

I've found these helpful in finding exactly where we fail to consolidate
state, leading to state explosions and false negatives due to the
thresholds being reached.

The patch also adds a "superedge::dump" member function I found myself
needing.

gcc/ChangeLog:
	* Makefile.in (ANALYZER_OBJS): Add analyzer/bar-chart.o.

gcc/analyzer/ChangeLog:
	* bar-chart.cc: New file.
	* bar-chart.h: New file.
	* engine.cc: Include "analyzer/bar-chart.h".
	(stats::log): Only log the m_num_nodes kinds that are non-zero.
	(stats::dump): Likewise when dumping.
	(stats::get_total_enodes): New.
	(exploded_graph::get_or_create_node): Increment the per-point-data
	m_excess_enodes when hitting the per-program-point limit on
	enodes.
	(exploded_graph::print_bar_charts): New.
	(exploded_graph::log_stats): Log the number of unprocessed enodes
	in the worklist.  Call print_bar_charts.
	(exploded_graph::dump_stats): Print the number of unprocessed
	enodes in the worklist.
	* exploded-graph.h (stats::get_total_enodes): New decl.
	(struct per_program_point_data): Add field m_excess_enodes.
	(exploded_graph::print_bar_charts): New decl.
	* supergraph.cc (superedge::dump): New.
	(superedge::dump): New.
	* supergraph.h (supernode::get_function): New.
	(superedge::dump): New decl.
	(superedge::dump): New decl.

gcc/ChangeLog

@@ -1,3 +1,7 @@
+2020-02-26  David Malcolm  <dmalcolm@redhat.com>
+
+	* Makefile.in (ANALYZER_OBJS): Add analyzer/bar-chart.o.
+
 2020-02-26  Jakub Jelinek  <jakub@redhat.com>
 
 	PR tree-optimization/93820

gcc/Makefile.in

@@ -1221,6 +1221,7 @@ ANALYZER_OBJS = \
 	analyzer/analyzer-logging.o \
 	analyzer/analyzer-pass.o \
 	analyzer/analyzer-selftests.o \
+	analyzer/bar-chart.o \
 	analyzer/call-string.o \
 	analyzer/checker-path.o \
 	analyzer/constraint-manager.o \

gcc/analyzer/ChangeLog

@@ -1,3 +1,28 @@
+2020-02-26  David Malcolm  <dmalcolm@redhat.com>
+
+	* bar-chart.cc: New file.
+	* bar-chart.h: New file.
+	* engine.cc: Include "analyzer/bar-chart.h".
+	(stats::log): Only log the m_num_nodes kinds that are non-zero.
+	(stats::dump): Likewise when dumping.
+	(stats::get_total_enodes): New.
+	(exploded_graph::get_or_create_node): Increment the per-point-data
+	m_excess_enodes when hitting the per-program-point limit on
+	enodes.
+	(exploded_graph::print_bar_charts): New.
+	(exploded_graph::log_stats): Log the number of unprocessed enodes
+	in the worklist.  Call print_bar_charts.
+	(exploded_graph::dump_stats): Print the number of unprocessed
+	enodes in the worklist.
+	* exploded-graph.h (stats::get_total_enodes): New decl.
+	(struct per_program_point_data): Add field m_excess_enodes.
+	(exploded_graph::print_bar_charts): New decl.
+	* supergraph.cc (superedge::dump): New.
+	(superedge::dump): New.
+	* supergraph.h (supernode::get_function): New.
+	(superedge::dump): New decl.
+	(superedge::dump): New decl.
+
 2020-02-24  David Malcolm  <dmalcolm@redhat.com>
 
 	* engine.cc (exploded_graph::get_or_create_node): Dump the

gcc/analyzer/bar-chart.cc

@@ -0,0 +1,102 @@
+/* Support for plotting bar charts in dumps.
+   Copyright (C) 2020 Free Software Foundation, Inc.
+   Contributed by David Malcolm <dmalcolm@redhat.com>.
+
+This file is part of GCC.
+
+GCC is free software; you can redistribute it and/or modify it
+under the terms of the GNU General Public License as published by
+the Free Software Foundation; either version 3, or (at your option)
+any later version.
+
+GCC is distributed in the hope that it will be useful, but
+WITHOUT ANY WARRANTY; without even the implied warranty of
+MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+General Public License for more details.
+
+You should have received a copy of the GNU General Public License
+along with GCC; see the file COPYING3.  If not see
+<http://www.gnu.org/licenses/>.  */
+
+#include "config.h"
+#include "system.h"
+#include "coretypes.h"
+#include "pretty-print.h"
+#include "analyzer/bar-chart.h"
+
+#if ENABLE_ANALYZER
+
+namespace ana {
+
+/* class bar_chart.  */
+
+/* Add an item, taking a copy of NAME.  */
+
+void
+bar_chart::add_item (const char *name, value_t value)
+{
+  m_items.safe_push (new item (name, value));
+}
+
+/* Print the data to PP.  */
+
+void
+bar_chart::print (pretty_printer *pp) const
+{
+  /* Get maximum printing widths and maximum value.  */
+  size_t max_width_name = 0;
+  size_t max_width_value = 0;
+  value_t max_value = 0;
+  unsigned i;
+  item *item;
+  char digit_buffer[128];
+  FOR_EACH_VEC_ELT (m_items, i, item)
+    {
+      max_width_name = MAX (max_width_name, item->m_strlen);
+      sprintf (digit_buffer, "%li", item->m_value);
+      max_width_value = MAX (max_width_value, strlen (digit_buffer));
+      max_value = MAX (max_value, item->m_value);
+    }
+
+  /* Print items.  */
+  FOR_EACH_VEC_ELT (m_items, i, item)
+    {
+      /* Print left-aligned name, padding to max_width_name.  */
+      pp_string (pp, item->m_name);
+      print_padding (pp, max_width_name - item->m_strlen);
+
+      pp_string (pp, ": ");
+
+      /* Print right-aligned name, padding to max_width_value.  */
+      sprintf (digit_buffer, "%li", item->m_value);
+      const size_t value_width = strlen (digit_buffer);
+      print_padding (pp, max_width_value - value_width);
+      pp_string (pp, digit_buffer);
+
+      pp_character (pp, '|');
+
+      /* Print bar, scaled in proportion to max value.  */
+      const int max_width_bar
+	= MIN (max_value, 76 - (max_width_name + max_width_value + 4));
+      const int bar_width
+	= (max_value > 0 ? (max_width_bar * item->m_value) / max_value : 0);
+      for (int j = 0; j < bar_width; j++)
+	pp_character (pp, '#');
+      print_padding (pp, max_width_bar - bar_width);
+      pp_character (pp, '|');
+      pp_newline (pp);
+    }
+}
+
+/* Print COUNT spaces to PP.  */
+
+void
+bar_chart::print_padding (pretty_printer *pp, size_t count)
+{
+  for (size_t i = 0; i < count; i++)
+    pp_character (pp, ' ');
+}
+
+} // namespace ana
+
+#endif /* #if ENABLE_ANALYZER */

gcc/analyzer/bar-chart.h

@@ -0,0 +1,60 @@
+/* Support for plotting bar charts in dumps.
+   Copyright (C) 2020 Free Software Foundation, Inc.
+   Contributed by David Malcolm <dmalcolm@redhat.com>.
+
+This file is part of GCC.
+
+GCC is free software; you can redistribute it and/or modify it
+under the terms of the GNU General Public License as published by
+the Free Software Foundation; either version 3, or (at your option)
+any later version.
+
+GCC is distributed in the hope that it will be useful, but
+WITHOUT ANY WARRANTY; without even the implied warranty of
+MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+General Public License for more details.
+
+You should have received a copy of the GNU General Public License
+along with GCC; see the file COPYING3.  If not see
+<http://www.gnu.org/licenses/>.  */
+
+#ifndef GCC_ANALYZER_BAR_CHART_H
+#define GCC_ANALYZER_BAR_CHART_H
+
+namespace ana {
+
+/* A class for printing bar charts to a pretty_printer.
+
+   TODO(stage1): move to gcc subdir? */
+
+class bar_chart
+{
+public:
+  typedef unsigned long value_t;
+
+  /* Add an item, taking a copy of NAME.  */
+  void add_item (const char *name, value_t value);
+
+  /* Print the data to PP.  */
+  void print (pretty_printer *pp) const;
+
+private:
+  struct item
+  {
+    item (const char *name, value_t value)
+    : m_name (xstrdup (name)), m_strlen (strlen (name)) , m_value (value) {}
+    ~item () { free (m_name); }
+
+    char *m_name;
+    size_t m_strlen;
+    value_t m_value;
+  };
+
+  static void print_padding (pretty_printer *pp, size_t count);
+
+  auto_delete_vec<item> m_items;
+};
+
+} // namespace ana
+
+#endif /* GCC_ANALYZER_BAR_CHART_H */

gcc/analyzer/engine.cc

@@ -57,6 +57,7 @@ along with GCC; see the file COPYING3.  If not see
 #include "analyzer/analysis-plan.h"
 #include "analyzer/checker-path.h"
 #include "analyzer/state-purge.h"
+#include "analyzer/bar-chart.h"
 
 /* For an overview, see gcc/doc/analyzer.texi.  */
 
@@ -1527,9 +1528,10 @@ stats::log (logger *logger) const
 {
   gcc_assert (logger);
   for (int i = 0; i < NUM_POINT_KINDS; i++)
-    logger->log ("m_num_nodes[%s]: %i",
-		 point_kind_to_string (static_cast <enum point_kind> (i)),
-		 m_num_nodes[i]);
+    if (m_num_nodes[i] > 0)
+      logger->log ("m_num_nodes[%s]: %i",
+		   point_kind_to_string (static_cast <enum point_kind> (i)),
+		   m_num_nodes[i]);
   logger->log ("m_node_reuse_count: %i", m_node_reuse_count);
   logger->log ("m_node_reuse_after_merge_count: %i",
 	       m_node_reuse_after_merge_count);
@@ -1541,9 +1543,10 @@ void
 stats::dump (FILE *out) const
 {
   for (int i = 0; i < NUM_POINT_KINDS; i++)
-    fprintf (out, "m_num_nodes[%s]: %i\n",
-	     point_kind_to_string (static_cast <enum point_kind> (i)),
-	     m_num_nodes[i]);
+    if (m_num_nodes[i] > 0)
+      fprintf (out, "m_num_nodes[%s]: %i\n",
+	       point_kind_to_string (static_cast <enum point_kind> (i)),
+	       m_num_nodes[i]);
   fprintf (out, "m_node_reuse_count: %i\n", m_node_reuse_count);
   fprintf (out, "m_node_reuse_after_merge_count: %i\n",
 	   m_node_reuse_after_merge_count);
@@ -1553,6 +1556,17 @@ stats::dump (FILE *out) const
 	     (float)m_num_nodes[PK_AFTER_SUPERNODE] / (float)m_num_supernodes);
 }
 
+/* Return the total number of enodes recorded within this object.  */
+
+int
+stats::get_total_enodes () const
+{
+  int result = 0;
+  for (int i = 0; i < NUM_POINT_KINDS; i++)
+    result += m_num_nodes[i];
+  return result;
+}
+
 /* strongly_connected_components's ctor.  Tarjan's SCC algorithm.  */
 
 strongly_connected_components::
@@ -1982,6 +1996,7 @@ exploded_graph::get_or_create_node (const program_point &point,
 	logger->log ("not creating enode; too many at program point");
       warning_at (point.get_location (), OPT_Wanalyzer_too_complex,
 		  "terminating analysis for this program point");
+      per_point_data->m_excess_enodes++;
       return NULL;
     }
 
@@ -2606,6 +2621,100 @@ exploded_graph::get_or_create_function_stats (function *fn)
     }
 }
 
+/* Print bar charts to PP showing:
+   - the number of enodes per function, and
+   - for each function:
+     - the number of enodes per supernode/BB
+     - the number of excess enodes per supernode/BB beyond the
+       per-program-point limit, if there were any.  */
+
+void
+exploded_graph::print_bar_charts (pretty_printer *pp) const
+{
+  cgraph_node *cgnode;
+
+  pp_string (pp, "enodes per function:");
+  pp_newline (pp);
+  bar_chart enodes_per_function;
+  FOR_EACH_FUNCTION_WITH_GIMPLE_BODY (cgnode)
+    {
+      function *fn = cgnode->get_fun ();
+      const stats * const *s_ptr
+	= const_cast <function_stat_map_t &> (m_per_function_stats).get (fn);
+      enodes_per_function.add_item (function_name (fn),
+				    s_ptr ? (*s_ptr)->get_total_enodes () : 0);
+    }
+  enodes_per_function.print (pp);
+
+  /* Accumulate number of enodes per supernode.  */
+  auto_vec<unsigned> enodes_per_supernode (m_sg.num_nodes ());
+  for (int i = 0; i < m_sg.num_nodes (); i++)
+    enodes_per_supernode.quick_push (0);
+  int i;
+  exploded_node *enode;
+  FOR_EACH_VEC_ELT (m_nodes, i, enode)
+    {
+      const supernode *iter_snode = enode->get_supernode ();
+      if (!iter_snode)
+	continue;
+      enodes_per_supernode[iter_snode->m_index]++;
+    }
+
+  /* Accumulate excess enodes per supernode.  */
+  auto_vec<unsigned> excess_enodes_per_supernode (m_sg.num_nodes ());
+  for (int i = 0; i < m_sg.num_nodes (); i++)
+    excess_enodes_per_supernode.quick_push (0);
+  for (point_map_t::iterator iter = m_per_point_data.begin ();
+       iter != m_per_point_data.end (); ++iter)
+    {
+      const program_point *point = (*iter).first;
+      const supernode *iter_snode = point->get_supernode ();
+      if (!iter_snode)
+	continue;
+      const per_program_point_data *point_data = (*iter).second;
+      excess_enodes_per_supernode[iter_snode->m_index]
+	+= point_data->m_excess_enodes;
+    }
+
+  /* Show per-function bar_charts of enodes per supernode/BB.  */
+  pp_string (pp, "per-function enodes per supernode/BB:");
+  pp_newline (pp);
+  FOR_EACH_FUNCTION_WITH_GIMPLE_BODY (cgnode)
+    {
+      function *fn = cgnode->get_fun ();
+      pp_printf (pp, "function: %qs", function_name (fn));
+      pp_newline (pp);
+
+      bar_chart enodes_per_snode;
+      bar_chart excess_enodes_per_snode;
+      bool have_excess_enodes = false;
+      for (int i = 0; i < m_sg.num_nodes (); i++)
+	{
+	  const supernode *iter_snode = m_sg.get_node_by_index (i);
+	  if (iter_snode->get_function () != fn)
+	    continue;
+	  pretty_printer tmp_pp;
+	  pp_printf (&tmp_pp, "sn %i (bb %i)",
+		     iter_snode->m_index, iter_snode->m_bb->index);
+	  enodes_per_snode.add_item (pp_formatted_text (&tmp_pp),
+				     enodes_per_supernode[iter_snode->m_index]);
+	  const int num_excess
+	    = excess_enodes_per_supernode[iter_snode->m_index];
+	  excess_enodes_per_snode.add_item (pp_formatted_text (&tmp_pp),
+					    num_excess);
+	  if (num_excess)
+	    have_excess_enodes = true;
+	}
+      enodes_per_snode.print (pp);
+      if (have_excess_enodes)
+	{
+	  pp_printf (pp, "EXCESS ENODES:");
+	  pp_newline (pp);
+	  excess_enodes_per_snode.print (pp);
+	}
+    }
+}
+
 /* Write all stats information to this graph's logger, if any.  */
 
 void
@@ -2620,6 +2729,7 @@ exploded_graph::log_stats () const
   logger->log ("m_sg.num_nodes (): %i", m_sg.num_nodes ());
   logger->log ("m_nodes.length (): %i", m_nodes.length ());
   logger->log ("m_edges.length (): %i", m_edges.length ());
+  logger->log ("remaining enodes in worklist: %i", m_worklist.length ());
 
   logger->log ("global stats:");
   m_global_stats.log (logger);
@@ -2632,6 +2742,8 @@ exploded_graph::log_stats () const
       log_scope s (logger, function_name (fn));
       (*iter).second->log (logger);
     }
+
+  print_bar_charts (logger->get_printer ());
 }
 
 /* Dump all stats information to OUT.  */
@@ -2642,6 +2754,7 @@ exploded_graph::dump_stats (FILE *out) const
   fprintf (out, "m_sg.num_nodes (): %i\n", m_sg.num_nodes ());
   fprintf (out, "m_nodes.length (): %i\n", m_nodes.length ());
   fprintf (out, "m_edges.length (): %i\n", m_edges.length ());
+  fprintf (out, "remaining enodes in worklist: %i", m_worklist.length ());
 
   fprintf (out, "global stats:\n");
   m_global_stats.dump (out);

gcc/analyzer/exploded-graph.h

@@ -400,6 +400,8 @@ struct stats
   void log (logger *logger) const;
   void dump (FILE *out) const;
 
+  int get_total_enodes () const;
+
   int m_num_nodes[NUM_POINT_KINDS];
   int m_node_reuse_count;
   int m_node_reuse_after_merge_count;
@@ -466,11 +468,14 @@ struct eg_hash_map_traits
 struct per_program_point_data
 {
   per_program_point_data (const program_point &key)
-  : m_key (key)
+  : m_key (key), m_excess_enodes (0)
   {}
 
   const program_point m_key;
   auto_vec<exploded_node *> m_enodes;
+  /* The number of attempts to create an enode for this point
+     after exceeding --param=analyzer-max-enodes-per-program-point.  */
+  int m_excess_enodes;
 };
 
 /* Traits class for storing per-program_point data within
@@ -791,6 +796,8 @@ public:
   { return &m_per_call_string_data; }
 
 private:
+  void print_bar_charts (pretty_printer *pp) const;
+
   DISABLE_COPY_AND_ASSIGN (exploded_graph);
 
   const supergraph &m_sg;

gcc/analyzer/supergraph.cc

@@ -624,6 +624,29 @@ supernode::get_stmt_index (const gimple *stmt) const
   gcc_unreachable ();
 }
 
+/* Dump this superedge to PP.  */
+
+void
+superedge::dump (pretty_printer *pp) const
+{
+  pp_printf (pp, "edge: SN: %i -> SN: %i", m_src->m_index, m_dest->m_index);
+  dump_label_to_pp (pp, false);
+  pp_newline (pp);
+}
+
+/* Dump this superedge to stderr.  */
+
+DEBUG_FUNCTION void
+superedge::dump () const
+{
+  pretty_printer pp;
+  pp_format_decoder (&pp) = default_tree_printer;
+  pp_show_color (&pp) = pp_show_color (global_dc->printer);
+  pp.buffer->stream = stderr;
+  dump (&pp);
+  pp_flush (&pp);
+}
+
 /* Implementation of dedge::dump_dot for superedges.
    Write a .dot edge to GV representing this superedge.  */
 

gcc/analyzer/supergraph.h

@@ -216,6 +216,8 @@ class supernode : public dnode<supergraph_traits>
     m_phi_nodes (phi_nodes), m_index (index)
   {}
 
+  function *get_function () const { return m_fun; }
+
   bool entry_p () const
   {
     return m_bb == ENTRY_BLOCK_PTR_FOR_FN (m_fun);
@@ -280,6 +282,8 @@ class superedge : public dedge<supergraph_traits>
  public:
   virtual ~superedge () {}
 
+  void dump (pretty_printer *pp) const;
+  void dump () const;
   void dump_dot (graphviz_out *gv, const dump_args_t &args) const;
 
   virtual void dump_label_to_pp (pretty_printer *pp,