[committed] analyzer: improvements to logging/dumping

Message ID 20200226115915.5898-1-dmalcolm@redhat.com
State New
Headers show
Series
  • [committed] analyzer: improvements to logging/dumping
Related show

Commit Message

David Malcolm Feb. 26, 2020, 11:59 a.m.
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.

Successfully bootstrapped & regrtested on x86_64-pc-linux-gnu.
Pushed to master as 67fa274cd635ec3c8af635294b67f09e45e3c56a.

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/Makefile.in               |   1 +
 gcc/analyzer/bar-chart.cc     | 102 +++++++++++++++++++++++++++
 gcc/analyzer/bar-chart.h      |  60 ++++++++++++++++
 gcc/analyzer/engine.cc        | 125 ++++++++++++++++++++++++++++++++--
 gcc/analyzer/exploded-graph.h |   9 ++-
 gcc/analyzer/supergraph.cc    |  23 +++++++
 gcc/analyzer/supergraph.h     |   4 ++
 7 files changed, 317 insertions(+), 7 deletions(-)
 create mode 100644 gcc/analyzer/bar-chart.cc
 create mode 100644 gcc/analyzer/bar-chart.h

-- 
2.21.0

Patch

diff --git a/gcc/Makefile.in b/gcc/Makefile.in
index b1423d1dbfd..fa9923bb270 100644
--- a/gcc/Makefile.in
+++ b/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 \
diff --git a/gcc/analyzer/bar-chart.cc b/gcc/analyzer/bar-chart.cc
new file mode 100644
index 00000000000..d0e30b68d0f
--- /dev/null
+++ b/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 */
diff --git a/gcc/analyzer/bar-chart.h b/gcc/analyzer/bar-chart.h
new file mode 100644
index 00000000000..07e93c5e394
--- /dev/null
+++ b/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 */
diff --git a/gcc/analyzer/engine.cc b/gcc/analyzer/engine.cc
index 45578f5111f..9c3b5adc09b 100644
--- a/gcc/analyzer/engine.cc
+++ b/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);
diff --git a/gcc/analyzer/exploded-graph.h b/gcc/analyzer/exploded-graph.h
index 7c2612d7b85..c3bd383e924 100644
--- a/gcc/analyzer/exploded-graph.h
+++ b/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;
diff --git a/gcc/analyzer/supergraph.cc b/gcc/analyzer/supergraph.cc
index fb4dbdfd8b9..e4c067606e0 100644
--- a/gcc/analyzer/supergraph.cc
+++ b/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.  */
 
diff --git a/gcc/analyzer/supergraph.h b/gcc/analyzer/supergraph.h
index 2c94f0544ce..ddb674da3b1 100644
--- a/gcc/analyzer/supergraph.h
+++ b/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,