[v3,8/8] Improve logging of scheduler dependency analysis context

Scheduler dependency analysis uses two main data structures:
1. reg_pending_* data contains effects of INSN on the register file,
   which is then incorporated into ...
2. deps_desc object, which contains commulative information about all
   instructions processed from deps_desc object's initialization.

This patch adds debug dumping of (2).

Dependency analysis contexts (aka deps_desc objects) are huge, but
each instruction affects only a small amount of data in these objects.
Therefore, it is most useful to dump differential information
compared to the dependency state after previous instruction.

gcc/ChangeLog:

	* sched-deps.cc (reset_deps, dump_rtx_insn_list)
	(rtx_insn_list_same_p):	New helper functions.
	(dump_deps_desc_diff): New function to dump dependency information.
	(sched_analysis_prev_deps): New static variable.
	(sched_analyze_insn): Dump dependency information.
	(init_deps_global, finish_deps_global): Handle sched_analysis_prev_deps.
	* sched-int.h (struct deps_reg): Update comments.
	* sched-rgn.cc (concat_insn_list, concat_expr_list): Update comments.
---
 gcc/sched-deps.cc | 197 ++++++++++++++++++++++++++++++++++++++++++++++
 gcc/sched-int.h   |   9 ++-
 gcc/sched-rgn.cc  |   5 ++
 3 files changed, 210 insertions(+), 1 deletion(-)

Dear scheduler maintainers,

Gentle ping.  This patch improves debugging output, it does not touch
scheduling logic.

On Wed, 22 Nov 2023 at 15:15, Maxim Kuvyrkov <maxim.kuvyrkov@linaro.org>
wrote:

> Scheduler dependency analysis uses two main data structures:
> 1. reg_pending_* data contains effects of INSN on the register file,
>    which is then incorporated into ...
> 2. deps_desc object, which contains commulative information about all
>    instructions processed from deps_desc object's initialization.
>
> This patch adds debug dumping of (2).
>
> Dependency analysis contexts (aka deps_desc objects) are huge, but
> each instruction affects only a small amount of data in these objects.
> Therefore, it is most useful to dump differential information
> compared to the dependency state after previous instruction.
>
> gcc/ChangeLog:
>
>         * sched-deps.cc (reset_deps, dump_rtx_insn_list)
>         (rtx_insn_list_same_p): New helper functions.
>         (dump_deps_desc_diff): New function to dump dependency information.
>         (sched_analysis_prev_deps): New static variable.
>         (sched_analyze_insn): Dump dependency information.
>         (init_deps_global, finish_deps_global): Handle
> sched_analysis_prev_deps.
>         * sched-int.h (struct deps_reg): Update comments.
>         * sched-rgn.cc (concat_insn_list, concat_expr_list): Update
> comments.
> ---
>  gcc/sched-deps.cc | 197 ++++++++++++++++++++++++++++++++++++++++++++++
>  gcc/sched-int.h   |   9 ++-
>  gcc/sched-rgn.cc  |   5 ++
>  3 files changed, 210 insertions(+), 1 deletion(-)
>
> diff --git a/gcc/sched-deps.cc b/gcc/sched-deps.cc
> index f9290c82fd2..edca9927e23 100644
> --- a/gcc/sched-deps.cc
> +++ b/gcc/sched-deps.cc
> @@ -1677,6 +1677,15 @@ delete_all_dependences (rtx_insn *insn)
>      sd_delete_dep (sd_it);
>  }
>
> +/* Re-initialize existing dependency context DEPS to be a copy of FROM.
> */
> +static void
> +reset_deps (class deps_desc *deps, class deps_desc *from)
> +{
> +  free_deps (deps);
> +  init_deps (deps, false);
> +  deps_join (deps, from);
> +}
> +
>  /* All insns in a scheduling group except the first should only have
>     dependencies on the previous insn in the group.  So we find the
>     first instruction in the scheduling group by walking the dependence
> @@ -2960,6 +2969,177 @@ dump_reg_pending_data (FILE *file, rtx_insn *insn)
>      }
>  }
>
> +/* Dump rtx_insn_list LIST.
> +   Consider moving to lists.cc if there are users outside of
> sched-deps.cc.  */
> +static void
> +dump_rtx_insn_list (FILE *file, rtx_insn_list *list)
> +{
> +  for (; list; list = list->next ())
> +    fprintf (file, " %d", INSN_UID (list->insn ()));
> +}
> +
> +/* Return TRUE if lists A and B have same elements in the same order.  */
> +static bool
> +rtx_insn_list_same_p (rtx_insn_list *a, rtx_insn_list *b)
> +{
> +  for (; a && b; a = a->next (), b = b->next ())
> +    if (a->insn () != b->insn ())
> +      return false;
> +
> +  if (a || b)
> +    return false;
> +
> +  return true;
> +}
> +
> +/* Dump parts of DEPS that are different from PREV.
> +   Dumping all information from dependency context produces huge
> +   hard-to-analize logs; differential dumping is way more managable.  */
> +static void
> +dump_deps_desc_diff (FILE *file, class deps_desc *deps, class deps_desc
> *prev)
> +{
> +  /* Each "paragraph" is a single line of output.  */
> +
> +  /* Note on param_max_pending_list_length:
> +     During normal dependency analysis various lists should not exceed
> this
> +     limit.  Searching for "!!!" in scheduler logs can point to potential
> bugs
> +     or poorly-handled corner-cases.  */
> +
> +  if (!rtx_insn_list_same_p (deps->pending_read_insns,
> +                            prev->pending_read_insns))
> +    {
> +      fprintf (file, ";; deps pending mem reads length(%d):",
> +              deps->pending_read_list_length);
> +      if ((deps->pending_read_list_length +
> deps->pending_write_list_length)
> +         >= param_max_pending_list_length)
> +       fprintf (file, "%d insns!!!", deps->pending_read_list_length);
> +      else
> +       dump_rtx_insn_list (file, deps->pending_read_insns);
> +      fprintf (file, "\n");
> +    }
> +
> +  if (!rtx_insn_list_same_p (deps->pending_write_insns,
> +                            prev->pending_write_insns))
> +    {
> +      fprintf (file, ";; deps pending mem writes length(%d):",
> +              deps->pending_write_list_length);
> +      if ((deps->pending_read_list_length +
> deps->pending_write_list_length)
> +         >= param_max_pending_list_length)
> +       fprintf (file, "%d insns!!!", deps->pending_write_list_length);
> +      else
> +       dump_rtx_insn_list (file, deps->pending_write_insns);
> +      fprintf (file, "\n");
> +    }
> +
> +  if (!rtx_insn_list_same_p (deps->pending_jump_insns,
> +                            prev->pending_jump_insns))
> +    {
> +      fprintf (file, ";; deps pending jump length(%d):",
> +              deps->pending_flush_length);
> +      if (deps->pending_flush_length >= param_max_pending_list_length)
> +       fprintf (file, "%d insns!!!", deps->pending_flush_length);
> +      else
> +       dump_rtx_insn_list (file, deps->pending_jump_insns);
> +      fprintf (file, "\n");
> +    }
> +
> +  fprintf (file, ";; last");
> +  if (!rtx_insn_list_same_p (deps->last_pending_memory_flush,
> +                            prev->last_pending_memory_flush))
> +    {
> +      fprintf (file, " memory_flush(");
> +      dump_rtx_insn_list (file, deps->last_pending_memory_flush);
> +      fprintf (file, ")");
> +    }
> +  if (!rtx_insn_list_same_p (deps->last_function_call,
> +                            prev->last_function_call))
> +    {
> +      fprintf (file, " call(");
> +      dump_rtx_insn_list (file, deps->last_function_call);
> +      fprintf (file, ")");
> +    }
> +  if (!rtx_insn_list_same_p (deps->last_function_call_may_noreturn,
> +                            prev->last_function_call_may_noreturn))
> +    {
> +      fprintf (file, " noreturn(");
> +      dump_rtx_insn_list (file, deps->last_function_call_may_noreturn);
> +      fprintf (file, ")");
> +    }
> +  fprintf (file, "\n");
> +
> +  fprintf (file, ";; sched_before_next");
> +  if (!rtx_insn_list_same_p (deps->sched_before_next_call,
> +                            prev->sched_before_next_call))
> +    {
> +      fprintf (file, " call(");
> +      dump_rtx_insn_list (file, deps->sched_before_next_call);
> +      fprintf (file, ")");
> +    }
> +  if (!rtx_insn_list_same_p (deps->sched_before_next_jump,
> +                            prev->sched_before_next_jump))
> +    {
> +      fprintf (file, " jump(");
> +      dump_rtx_insn_list (file, deps->sched_before_next_jump);
> +      fprintf (file, ")");
> +    }
> +  fprintf (file, " in_post_call_group_p(%d)\n",
> deps->in_post_call_group_p);
> +
> +  fprintf (file, ";; last_debug_insn(%d) last_args_size(%d)
> last_prologue(",
> +          deps->last_debug_insn ? INSN_UID (deps->last_debug_insn) : -1,
> +          deps->last_args_size ? INSN_UID (deps->last_args_size) : -1);
> +  dump_rtx_insn_list (file, deps->last_prologue);
> +  fprintf (file, ") last_epilogue(");
> +  dump_rtx_insn_list (file, deps->last_epilogue);
> +  fprintf (file, ") last_logue_was_epilogue(%d)\n",
> +          deps->last_logue_was_epilogue);
> +
> +  int i;
> +
> +  gcc_assert (deps->max_reg == prev->max_reg);
> +  for (i = 0; i < deps->max_reg; ++i)
> +    {
> +      struct deps_reg *reg_last = &deps->reg_last[i];
> +      struct deps_reg *reg_prev = &prev->reg_last[i];
> +
> +      if (rtx_insn_list_same_p (reg_last->uses, reg_prev->uses)
> +         && rtx_insn_list_same_p (reg_last->sets, reg_prev->sets)
> +         && rtx_insn_list_same_p (reg_last->implicit_sets,
> +                                  reg_prev->implicit_sets)
> +         && rtx_insn_list_same_p (reg_last->control_uses,
> +                                  reg_prev->control_uses)
> +         && rtx_insn_list_same_p (reg_last->clobbers,
> +                                  reg_prev->clobbers))
> +       continue;
> +
> +      fprintf (file, ";; reg %u: uses(", i);
> +      if (reg_last->uses_length >= param_max_pending_list_length)
> +       fprintf (file, "%d insns!!!", reg_last->uses_length);
> +      else
> +       dump_rtx_insn_list (file, reg_last->uses);
> +      if (reg_last->clobbers_length >= param_max_pending_list_length)
> +       {
> +         fprintf (file, ") clobbers(");
> +         fprintf (file, "%d insns!!!", reg_last->clobbers_length);
> +       }
> +      else
> +       {
> +         fprintf (file, ") sets(");
> +         dump_rtx_insn_list (file, reg_last->sets);
> +         fprintf (file, ") implicit_sets(");
> +         dump_rtx_insn_list (file, reg_last->implicit_sets);
> +         fprintf (file, ") control_uses(");
> +         dump_rtx_insn_list (file, reg_last->control_uses);
> +         fprintf (file, ") clobbers(");
> +         dump_rtx_insn_list (file, reg_last->clobbers);
> +       }
> +      fprintf (file, ")\n");
> +    }
> +}
> +
> +/* Dependency analysis state before current insn.
> +   Used by dump_deps_desc_diff().  */
> +static class deps_desc *sched_analysis_prev_deps;
> +
>  /* Analyze an INSN with pattern X to find all dependencies.
>     This analysis uses two main data structures:
>     1. reg_pending_* data contains effects of INSN on the register file,
> @@ -3627,6 +3807,16 @@ sched_analyze_insn (class deps_desc *deps, rtx x,
> rtx_insn *insn)
>           deps->last_logue_was_epilogue = true;
>         }
>      }
> +
> +    if (sched_verbose >= 8)
> +      {
> +       dump_deps_desc_diff (sched_dump, deps, sched_analysis_prev_deps);
> +       reset_deps (sched_analysis_prev_deps, deps);
> +       fprintf (sched_dump, ";; ");
> +       dump_lists (sched_dump, insn, SD_LIST_BACK,
> +                   DUMP_LISTS_ALL | DUMP_DEP_PRO);
> +       fprintf (sched_dump, "\n");
> +      }
>  }
>
>  /* Return TRUE if INSN might not always return normally (e.g. call exit,
> @@ -4305,6 +4495,9 @@ init_deps_global (void)
>        sched_deps_info->note_mem_dep = haifa_note_mem_dep;
>        sched_deps_info->note_dep = haifa_note_dep;
>     }
> +
> +  sched_analysis_prev_deps = XNEW (class deps_desc);
> +  init_deps (sched_analysis_prev_deps, false);
>  }
>
>  /* Free everything used by the dependency analysis code.  */
> @@ -4316,6 +4509,10 @@ finish_deps_global (void)
>    FREE_REG_SET (reg_pending_clobbers);
>    FREE_REG_SET (reg_pending_uses);
>    FREE_REG_SET (reg_pending_control_uses);
> +
> +  free_deps (sched_analysis_prev_deps);
> +  free (sched_analysis_prev_deps);
> +  sched_analysis_prev_deps = NULL;
>  }
>
>  /* Estimate the weakness of dependence between MEM1 and MEM2.  */
> diff --git a/gcc/sched-int.h b/gcc/sched-int.h
> index 64a2f0bcff9..8a3109ce86e 100644
> --- a/gcc/sched-int.h
> +++ b/gcc/sched-int.h
> @@ -455,7 +455,9 @@ struct deps_reg
>    int clobbers_length;
>  };
>
> -/* Describe state of dependencies used during sched_analyze phase.  */
> +/* Describe state of dependencies used during sched_analyze phase.
> +   Please consider updating sched-deps.cc:dump_deps_desc_diff() when
> adding
> +   new fields.  */
>  class deps_desc
>  {
>  public:
> @@ -499,6 +501,11 @@ public:
>       large lists.  */
>    int pending_flush_length;
>
> +  /* Below are lists (and not just a single instructions) to allow
> inter-block
> +     dependency analysis.  Each block
> +     may add a single insn to below lists, but when merging dependency
> +     analysis context from multiple predecessor blocks, we may get a
> list.  */
> +
>    /* The last insn upon which all memory references must depend.
>       This is an insn which flushed the pending lists, creating a
> dependency
>       between it and all previously pending memory references.  This
> creates
> diff --git a/gcc/sched-rgn.cc b/gcc/sched-rgn.cc
> index da3ec0458ff..72f0a2de66e 100644
> --- a/gcc/sched-rgn.cc
> +++ b/gcc/sched-rgn.cc
> @@ -2590,6 +2590,10 @@ static rtx_insn_list *
>  concat_insn_list (rtx_insn_list *copy, rtx_insn_list *old)
>  {
>    if (!old)
> +    /* concat_*_LIST() will return a reversed copy of COPY.  Working with
> +       reversed copies would complicate dependency dumping in
> +       dump_deps_desc_diff(), which internally uses reset_deps() and
> +       deps_join().  Therefore, use copy_INSN_LIST() when OLD is NULL.  */
>      return copy_INSN_LIST (copy);
>    return concat_INSN_LIST (copy, old);
>  }
> @@ -2599,6 +2603,7 @@ static rtx_expr_list *
>  concat_expr_list (rtx_expr_list *copy, rtx_expr_list *old)
>  {
>    if (!old)
> +    /* See comment in concat_insn_list() above.  */
>      return copy_EXPR_LIST (copy);
>    return concat_EXPR_LIST (copy, old);
>  }
> --
> 2.34.1
>
>