analyzer: improvements to logging/dumping
authorDavid Malcolm <dmalcolm@redhat.com>
Fri, 21 Feb 2020 14:28:55 +0000 (09:28 -0500)
committerDavid Malcolm <dmalcolm@redhat.com>
Wed, 26 Feb 2020 11:57:22 +0000 (06:57 -0500)
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
gcc/Makefile.in
gcc/analyzer/ChangeLog
gcc/analyzer/bar-chart.cc [new file with mode: 0644]
gcc/analyzer/bar-chart.h [new file with mode: 0644]
gcc/analyzer/engine.cc
gcc/analyzer/exploded-graph.h
gcc/analyzer/supergraph.cc
gcc/analyzer/supergraph.h

index f3da501ef110f172bcc1aaa775deda170baaf1e6..7504b13022263110fc505664626f1a7dad8eba28 100644 (file)
@@ -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
index b1423d1dbfde4cda9c03ff908c569987daba8730..fa9923bb27032fba3ae54ed5cb54b255a6706665 100644 (file)
@@ -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 \
index f92b56f68c68c2097c275de5ea24dc7333cb647e..982cc3ca9fd48643cfe3656acc9c4cb10b2f3f24 100644 (file)
@@ -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
diff --git a/gcc/analyzer/bar-chart.cc b/gcc/analyzer/bar-chart.cc
new file mode 100644 (file)
index 0000000..d0e30b6
--- /dev/null
@@ -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 (file)
index 0000000..07e93c5
--- /dev/null
@@ -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 */
index 45578f5111f8bc36d95048975c85f11cf3f0aa7b..9c3b5adc09b305049ef32918b9c5c07a7c7795df 100644 (file)
@@ -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);
index 7c2612d7b85eeaf9e44fdefcffdecbbcdb0682be..c3bd383e924573fb86ac2b439e1492742e9ad92d 100644 (file)
@@ -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;
index fb4dbdfd8b9994d19ae830bd076d3d4394fcfc33..e4c067606e0c1330f208d8d24fe76c8cdb115541 100644 (file)
@@ -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.  */
 
index 2c94f0544ce24748d53520ec0c833033f50ba170..ddb674da3b1934618ca6593f234e6c068e6a7937 100644 (file)
@@ -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,