[v6] gdb: Buffer output streams during events that might download debuginfo

  v5: https://sourceware.org/pipermail/gdb-patches/2023-August/201648.html

v6 adds buffering for the uiout argument passed to do_with_buffered_output.
Also get_unbuffered_stream now recursively calls itself.

Commit message:

Introduce new ui_file buffering_file to temporarily collect output
written to gdb_std* output streams during print_thread, print_frame_info
and print_stop_event.

This ensures that output during these functions is not interrupted
by debuginfod progress messages.

With the addition of deferred debuginfo downloading it is possible
for download progress messages to print during these events.
Without any intervention we can end up with poorly formatted output:

    (gdb) backtrace
    [...]
    #8  0x00007fbe8af7d7cf in pygi_invoke_c_callable (Downloading separate debug info for /lib64/libpython3.11.so.1.0
    function_cache=0x561221b224d0, state=<optimized out>...

To fix this we buffer writes to gdb_std* output streams while allowing
debuginfod progress messages to skip the buffers and print to the
underlying output streams immediately.  Buffered output is then written
to the output streams.  This ensures that progress messages print first,
followed by uninterrupted frame/thread/stop info:

    (gdb) backtrace
    [...]
    Downloading separate debug info for /lib64/libpython3.11.so.1.0
    #8  0x00007fbe8af7d7cf in pygi_invoke_c_callable (function_cache=0x561221b224d0, state=<optimized out>...

Co-Authored-By: Andrew Burgess <aburgess@redhat.com>
---
 gdb/cli-out.c            |  21 ++--
 gdb/cli-out.h            |   3 +
 gdb/debuginfod-support.c |  15 ++-
 gdb/infrun.c             |  16 +++-
 gdb/mi/mi-out.c          |   9 +-
 gdb/mi/mi-out.h          |   3 +
 gdb/python/py-mi.c       |   3 +
 gdb/stack.c              |  35 +++++--
 gdb/thread.c             | 171 +++++++++++++++++++--------------
 gdb/ui-file.h            |   2 +-
 gdb/ui-out.c             | 134 ++++++++++++++++++++++++++
 gdb/ui-out.h             | 200 +++++++++++++++++++++++++++++++++++++++
 12 files changed, 514 insertions(+), 98 deletions(-)
  

Aaron Merey <amerey@redhat.com> writes:

> v5: https://sourceware.org/pipermail/gdb-patches/2023-August/201648.html
>
> v6 adds buffering for the uiout argument passed to do_with_buffered_output.
> Also get_unbuffered_stream now recursively calls itself.

Great spot.  I had been reviewing V5, and this was one of the issues I
was going to raise!

>
> Commit message:
>
> Introduce new ui_file buffering_file to temporarily collect output
> written to gdb_std* output streams during print_thread, print_frame_info
> and print_stop_event.
>
> This ensures that output during these functions is not interrupted
> by debuginfod progress messages.
>
> With the addition of deferred debuginfo downloading it is possible
> for download progress messages to print during these events.
> Without any intervention we can end up with poorly formatted output:
>
>     (gdb) backtrace
>     [...]
>     #8  0x00007fbe8af7d7cf in pygi_invoke_c_callable (Downloading separate debug info for /lib64/libpython3.11.so.1.0
>     function_cache=0x561221b224d0, state=<optimized out>...
>
> To fix this we buffer writes to gdb_std* output streams while allowing
> debuginfod progress messages to skip the buffers and print to the
> underlying output streams immediately.  Buffered output is then written
> to the output streams.  This ensures that progress messages print first,
> followed by uninterrupted frame/thread/stop info:
>
>     (gdb) backtrace
>     [...]
>     Downloading separate debug info for /lib64/libpython3.11.so.1.0
>     #8  0x00007fbe8af7d7cf in pygi_invoke_c_callable (function_cache=0x561221b224d0, state=<optimized out>...
>
> Co-Authored-By: Andrew Burgess <aburgess@redhat.com>
> ---
>  gdb/cli-out.c            |  21 ++--
>  gdb/cli-out.h            |   3 +
>  gdb/debuginfod-support.c |  15 ++-
>  gdb/infrun.c             |  16 +++-
>  gdb/mi/mi-out.c          |   9 +-
>  gdb/mi/mi-out.h          |   3 +
>  gdb/python/py-mi.c       |   3 +
>  gdb/stack.c              |  35 +++++--
>  gdb/thread.c             | 171 +++++++++++++++++++--------------
>  gdb/ui-file.h            |   2 +-
>  gdb/ui-out.c             | 134 ++++++++++++++++++++++++++
>  gdb/ui-out.h             | 200 +++++++++++++++++++++++++++++++++++++++
>  12 files changed, 514 insertions(+), 98 deletions(-)
>
> diff --git a/gdb/cli-out.c b/gdb/cli-out.c
> index 20d3d93f1ad..a570a2d939d 100644
> --- a/gdb/cli-out.c
> +++ b/gdb/cli-out.c
> @@ -299,7 +299,7 @@ cli_ui_out::do_progress_notify (const std::string &msg,
>  				double howmuch, double total)
>  {
>    int chars_per_line = get_chars_per_line ();
> -  struct ui_file *stream = m_streams.back ();
> +  struct ui_file *stream = get_unbuffered (m_streams.back ());
>    cli_progress_info &info (m_progress_info.back ());
>  
>    if (chars_per_line > MAX_CHARS_PER_LINE)
> @@ -307,16 +307,23 @@ cli_ui_out::do_progress_notify (const std::string &msg,
>  
>    if (info.state == progress_update::START)
>      {
> +      std::string prefix;
> +      if (cur_prefix_state == prefix_state_t::NEWLINE_NEEDED)
> +	{
> +	  prefix = "\n";
> +	  cur_prefix_state = prefix_state_t::NEWLINE_PRINTED;
> +	}
> +

Unless I'm missing something, none of this cur_prefix_state stuff can
trigger after this commit; the cur_prefix_state starts as
prefix_state_t::NEWLINE_OFF and can never change from that state.

I know this changes after later patches in this series, but it feels
like this work has ended up in this patch by mistake.

Could we remove these changes from this commit and push them into a
later commit in this series?


>        if (stream->isatty ()
>  	  && current_ui->input_interactive_p ()
>  	  && chars_per_line >= MIN_CHARS_PER_LINE)
>  	{
> -	  gdb_printf (stream, "%s\n", msg.c_str ());
> +	  gdb_printf (stream, "%s\n", (prefix + msg).c_str ());
>  	  info.state = progress_update::BAR;
>  	}
>        else
>  	{
> -	  gdb_printf (stream, "%s...\n", msg.c_str ());
> +	  gdb_printf (stream, "%s...\n", (prefix + msg).c_str ());
>  	  info.state = progress_update::WORKING;
>  	}
>      }
> @@ -384,7 +391,7 @@ cli_ui_out::do_progress_notify (const std::string &msg,
>  void
>  cli_ui_out::clear_progress_notify ()
>  {
> -  struct ui_file *stream = m_streams.back ();
> +  struct ui_file *stream = get_unbuffered (m_streams.back ());
>    int chars_per_line = get_chars_per_line ();
>  
>    scoped_restore save_pagination
> @@ -413,10 +420,12 @@ void
>  cli_ui_out::do_progress_end ()
>  {
>    struct ui_file *stream = m_streams.back ();
> -  m_progress_info.pop_back ();
> +  cli_progress_info &info (m_progress_info.back ());
>  
> -  if (stream->isatty ())
> +  if (stream->isatty () && info.state != progress_update::START)
>      clear_progress_notify ();
> +
> +  m_progress_info.pop_back ();
>  }
>  
>  /* local functions */
> diff --git a/gdb/cli-out.h b/gdb/cli-out.h
> index 34016182269..89b4aa40870 100644
> --- a/gdb/cli-out.h
> +++ b/gdb/cli-out.h
> @@ -35,6 +35,9 @@ class cli_ui_out : public ui_out
>  
>    bool can_emit_style_escape () const override;
>  
> +  ui_file *current_stream () const override
> +  { return m_streams.back (); }
> +
>  protected:
>  
>    virtual void do_table_begin (int nbrofcols, int nr_rows,
> diff --git a/gdb/debuginfod-support.c b/gdb/debuginfod-support.c
> index 902af405cc6..b36fb8c35de 100644
> --- a/gdb/debuginfod-support.c
> +++ b/gdb/debuginfod-support.c
> @@ -155,7 +155,8 @@ progressfn (debuginfod_client *c, long cur, long total)
>  
>    if (check_quit_flag ())
>      {
> -      gdb_printf ("Cancelling download of %s %s...\n",
> +      ui_file *outstream = get_unbuffered (gdb_stdout);
> +      gdb_printf (outstream, _("Cancelling download of %s %s...\n"),
>  		  data->desc, styled_fname.c_str ());
>        return 1;
>      }
> @@ -296,10 +297,14 @@ static void
>  print_outcome (int fd, const char *desc, const char *fname)
>  {
>    if (fd < 0 && fd != -ENOENT)
> -    gdb_printf (_("Download failed: %s.  Continuing without %s %ps.\n"),
> -		safe_strerror (-fd),
> -		desc,
> -		styled_string (file_name_style.style (), fname));
> +    {
> +      ui_file *outstream = get_unbuffered (gdb_stdout);
> +      gdb_printf (outstream,
> +		  _("Download failed: %s.  Continuing without %s %ps.\n"),
> +		  safe_strerror (-fd),
> +		  desc,
> +		  styled_string (file_name_style.style (), fname));
> +    }
>  }
>  
>  /* See debuginfod-support.h  */
> diff --git a/gdb/infrun.c b/gdb/infrun.c
> index 4730d290442..b52f447f124 100644
> --- a/gdb/infrun.c
> +++ b/gdb/infrun.c
> @@ -8785,10 +8785,10 @@ print_stop_location (const target_waitstatus &ws)
>      print_stack_frame (get_selected_frame (nullptr), 0, source_flag, 1);
>  }
>  
> -/* See infrun.h.  */
> +/* See `print_stop_event` in infrun.h.  */
>  
> -void
> -print_stop_event (struct ui_out *uiout, bool displays)
> +static void
> +do_print_stop_event (struct ui_out *uiout, bool displays)
>  {
>    struct target_waitstatus last;
>    struct thread_info *tp;
> @@ -8817,6 +8817,16 @@ print_stop_event (struct ui_out *uiout, bool displays)
>      }
>  }
>  
> +/* See infrun.h.  This function itself sets up buffered output for the
> +   duration of do_print_stop_event, which performs the actual event
> +   printing.  */
> +
> +void
> +print_stop_event (struct ui_out *uiout, bool displays)
> +{
> +  do_with_buffered_output (do_print_stop_event, uiout, displays);
> +}
> +
>  /* See infrun.h.  */
>  
>  void
> diff --git a/gdb/mi/mi-out.c b/gdb/mi/mi-out.c
> index bbd21287b28..110864adac3 100644
> --- a/gdb/mi/mi-out.c
> +++ b/gdb/mi/mi-out.c
> @@ -278,7 +278,14 @@ mi_ui_out::do_progress_notify (const std::string &msg, const char *unit,
>  
>    if (info.state == progress_update::START)
>      {
> -      gdb_printf ("%s...\n", msg.c_str ());
> +      std::string prefix;
> +      if (cur_prefix_state == prefix_state_t::NEWLINE_NEEDED)
> +	{
> +	  prefix = "\n";
> +	  cur_prefix_state = prefix_state_t::NEWLINE_PRINTED;
> +	}
> +
> +      gdb_printf ("%s...\n", (prefix + msg).c_str ());
>        info.state = progress_update::WORKING;
>      }
>  }
> diff --git a/gdb/mi/mi-out.h b/gdb/mi/mi-out.h
> index 0dd7479a52f..68ff5faf632 100644
> --- a/gdb/mi/mi-out.h
> +++ b/gdb/mi/mi-out.h
> @@ -45,6 +45,9 @@ class mi_ui_out : public ui_out
>      return false;
>    }
>  
> +  ui_file *current_stream () const override
> +  { return m_streams.back (); }
> +
>  protected:
>  
>    virtual void do_table_begin (int nbrofcols, int nr_rows, const char *tblid)
> diff --git a/gdb/python/py-mi.c b/gdb/python/py-mi.c
> index 66dc6fb8a32..551edae6cc0 100644
> --- a/gdb/python/py-mi.c
> +++ b/gdb/python/py-mi.c
> @@ -55,6 +55,9 @@ class py_ui_out : public ui_out
>      return current ().obj.release ();
>    }
>  
> +  ui_file *current_stream () const override
> +  { return nullptr; }
> +
>  protected:
>  
>    void do_progress_end () override { }
> diff --git a/gdb/stack.c b/gdb/stack.c
> index 0b35d62f82f..0560261144c 100644
> --- a/gdb/stack.c
> +++ b/gdb/stack.c
> @@ -220,7 +220,8 @@ static void print_frame_local_vars (frame_info_ptr frame,
>  				    const char *regexp, const char *t_regexp,
>  				    int num_tabs, struct ui_file *stream);
>  
> -static void print_frame (const frame_print_options &opts,
> +static void print_frame (struct ui_out *uiout,
> +			 const frame_print_options &opts,
>  			 frame_info_ptr frame, int print_level,
>  			 enum print_what print_what,  int print_args,
>  			 struct symtab_and_line sal);
> @@ -1020,16 +1021,15 @@ get_user_print_what_frame_info (gdb::optional<enum print_what> *what)
>     Used in "where" output, and to emit breakpoint or step
>     messages.  */
>  
> -void
> -print_frame_info (const frame_print_options &fp_opts,
> -		  frame_info_ptr frame, int print_level,
> -		  enum print_what print_what, int print_args,
> -		  int set_current_sal)
> +static void
> +do_print_frame_info (struct ui_out *uiout, const frame_print_options &fp_opts,
> +		     frame_info_ptr frame, int print_level,
> +		     enum print_what print_what, int print_args,
> +		     int set_current_sal)
>  {
>    struct gdbarch *gdbarch = get_frame_arch (frame);
>    int source_print;
>    int location_print;
> -  struct ui_out *uiout = current_uiout;
>  
>    if (!current_uiout->is_mi_like_p ()
>        && fp_opts.print_frame_info != print_frame_info_auto)
> @@ -1105,7 +1105,8 @@ print_frame_info (const frame_print_options &fp_opts,
>  		    || print_what == LOC_AND_ADDRESS
>  		    || print_what == SHORT_LOCATION);
>    if (location_print || !sal.symtab)
> -    print_frame (fp_opts, frame, print_level, print_what, print_args, sal);
> +    print_frame (uiout, fp_opts, frame, print_level,
> +		 print_what, print_args, sal);
>  
>    source_print = (print_what == SRC_LINE || print_what == SRC_AND_LOC);
>  
> @@ -1185,6 +1186,20 @@ print_frame_info (const frame_print_options &fp_opts,
>    gdb_flush (gdb_stdout);
>  }
>  
> +/* Redirect output to a temporary buffer for the duration
> +   of do_print_frame_info.  */
> +
> +void
> +print_frame_info (const frame_print_options &fp_opts,
> +		  frame_info_ptr frame, int print_level,
> +		  enum print_what print_what, int print_args,
> +		  int set_current_sal)
> +{
> +  do_with_buffered_output (do_print_frame_info, current_uiout,
> +			   fp_opts, frame, print_level, print_what,
> +			   print_args, set_current_sal);
> +}
> +
>  /* See stack.h.  */
>  
>  void
> @@ -1309,13 +1324,13 @@ find_frame_funname (frame_info_ptr frame, enum language *funlang,
>  }
>  
>  static void
> -print_frame (const frame_print_options &fp_opts,
> +print_frame (struct ui_out *uiout,
> +	     const frame_print_options &fp_opts,
>  	     frame_info_ptr frame, int print_level,
>  	     enum print_what print_what, int print_args,
>  	     struct symtab_and_line sal)
>  {
>    struct gdbarch *gdbarch = get_frame_arch (frame);
> -  struct ui_out *uiout = current_uiout;
>    enum language funlang = language_unknown;
>    struct value_print_options opts;
>    struct symbol *func;
> diff --git a/gdb/thread.c b/gdb/thread.c
> index c8145da59bc..f6cf2eb9cf4 100644
> --- a/gdb/thread.c
> +++ b/gdb/thread.c
> @@ -1064,6 +1064,103 @@ thread_target_id_str (thread_info *tp)
>      return target_id;
>  }
>  
> +/* Print thread TP.  GLOBAL_IDS indicates whether REQUESTED_THREADS
> +   is a list of global or per-inferior thread ids.  */
> +
> +static void
> +do_print_thread (ui_out *uiout, const char *requested_threads,
> +		 int global_ids, int pid, int show_global_ids,
> +		 int default_inf_num, thread_info *tp,
> +		 thread_info *current_thread)
> +{
> +  int core;
> +
> +  if (!should_print_thread (requested_threads, default_inf_num,
> +			    global_ids, pid, tp))
> +    return;
> +
> +  ui_out_emit_tuple tuple_emitter (uiout, NULL);
> +
> +  if (!uiout->is_mi_like_p ())
> +    {
> +      if (tp == current_thread)
> +	uiout->field_string ("current", "*");
> +      else
> +	uiout->field_skip ("current");
> +
> +      uiout->field_string ("id-in-tg", print_thread_id (tp));
> +    }
> +
> +  if (show_global_ids || uiout->is_mi_like_p ())
> +    uiout->field_signed ("id", tp->global_num);
> +
> +  /* Switch to the thread (and inferior / target).  */
> +  switch_to_thread (tp);
> +
> +  /* For the CLI, we stuff everything into the target-id field.
> +     This is a gross hack to make the output come out looking
> +     correct.  The underlying problem here is that ui-out has no
> +     way to specify that a field's space allocation should be
> +     shared by several fields.  For MI, we do the right thing
> +     instead.  */
> +
> +  if (uiout->is_mi_like_p ())
> +    {
> +      uiout->field_string ("target-id", target_pid_to_str (tp->ptid));
> +
> +      const char *extra_info = target_extra_thread_info (tp);
> +      if (extra_info != nullptr)
> +	uiout->field_string ("details", extra_info);
> +
> +      const char *name = thread_name (tp);
> +      if (name != NULL)
> +	uiout->field_string ("name", name);
> +    }
> +  else
> +    {
> +      uiout->field_string ("target-id", thread_target_id_str (tp));
> +    }
> +
> +  if (tp->state == THREAD_RUNNING)
> +    uiout->text ("(running)\n");
> +  else
> +    {
> +      /* The switch above put us at the top of the stack (leaf
> +	 frame).  */
> +      print_stack_frame (get_selected_frame (NULL),
> +			 /* For MI output, print frame level.  */
> +			 uiout->is_mi_like_p (),
> +			 LOCATION, 0);
> +    }
> +
> +  if (uiout->is_mi_like_p ())
> +    {
> +      const char *state = "stopped";
> +
> +      if (tp->state == THREAD_RUNNING)
> +	state = "running";
> +      uiout->field_string ("state", state);
> +    }
> +
> +  core = target_core_of_thread (tp->ptid);
> +  if (uiout->is_mi_like_p () && core != -1)
> +    uiout->field_signed ("core", core);
> +}
> +
> +/* Redirect output to a temporary buffer for the duration
> +   of do_print_thread.  */
> +
> +static void
> +print_thread (ui_out *uiout, const char *requested_threads,
> +	      int global_ids, int pid, int show_global_ids,
> +	      int default_inf_num, thread_info *tp, thread_info *current_thread)
> +
> +{
> +  do_with_buffered_output (do_print_thread, uiout, requested_threads,
> +			   global_ids, pid, show_global_ids,
> +			   default_inf_num, tp, current_thread);
> +}
> +
>  /* Like print_thread_info, but in addition, GLOBAL_IDS indicates
>     whether REQUESTED_THREADS is a list of global or per-inferior
>     thread ids.  */
> @@ -1147,82 +1244,12 @@ print_thread_info_1 (struct ui_out *uiout, const char *requested_threads,
>      for (inferior *inf : all_inferiors ())
>        for (thread_info *tp : inf->threads ())
>  	{
> -	  int core;
> -
>  	  any_thread = true;
>  	  if (tp == current_thread && tp->state == THREAD_EXITED)
>  	    current_exited = true;
>  
> -	  if (!should_print_thread (requested_threads, default_inf_num,
> -				    global_ids, pid, tp))
> -	    continue;
> -
> -	  ui_out_emit_tuple tuple_emitter (uiout, NULL);
> -
> -	  if (!uiout->is_mi_like_p ())
> -	    {
> -	      if (tp == current_thread)
> -		uiout->field_string ("current", "*");
> -	      else
> -		uiout->field_skip ("current");
> -
> -	      uiout->field_string ("id-in-tg", print_thread_id (tp));
> -	    }
> -
> -	  if (show_global_ids || uiout->is_mi_like_p ())
> -	    uiout->field_signed ("id", tp->global_num);
> -
> -	  /* Switch to the thread (and inferior / target).  */
> -	  switch_to_thread (tp);
> -
> -	  /* For the CLI, we stuff everything into the target-id field.
> -	     This is a gross hack to make the output come out looking
> -	     correct.  The underlying problem here is that ui-out has no
> -	     way to specify that a field's space allocation should be
> -	     shared by several fields.  For MI, we do the right thing
> -	     instead.  */
> -
> -	  if (uiout->is_mi_like_p ())
> -	    {
> -	      uiout->field_string ("target-id", target_pid_to_str (tp->ptid));
> -
> -	      const char *extra_info = target_extra_thread_info (tp);
> -	      if (extra_info != nullptr)
> -		uiout->field_string ("details", extra_info);
> -
> -	      const char *name = thread_name (tp);
> -	      if (name != NULL)
> -		uiout->field_string ("name", name);
> -	    }
> -	  else
> -	    {
> -	      uiout->field_string ("target-id", thread_target_id_str (tp));
> -	    }
> -
> -	  if (tp->state == THREAD_RUNNING)
> -	    uiout->text ("(running)\n");
> -	  else
> -	    {
> -	      /* The switch above put us at the top of the stack (leaf
> -		 frame).  */
> -	      print_stack_frame (get_selected_frame (NULL),
> -				 /* For MI output, print frame level.  */
> -				 uiout->is_mi_like_p (),
> -				 LOCATION, 0);
> -	    }
> -
> -	  if (uiout->is_mi_like_p ())
> -	    {
> -	      const char *state = "stopped";
> -
> -	      if (tp->state == THREAD_RUNNING)
> -		state = "running";
> -	      uiout->field_string ("state", state);
> -	    }
> -
> -	  core = target_core_of_thread (tp->ptid);
> -	  if (uiout->is_mi_like_p () && core != -1)
> -	    uiout->field_signed ("core", core);
> +	  print_thread (uiout, requested_threads, global_ids, pid,
> +			show_global_ids, default_inf_num, tp, current_thread);
>  	}
>  
>      /* This end scope restores the current thread and the frame
> diff --git a/gdb/ui-file.h b/gdb/ui-file.h
> index 31f87ffd51d..8385033b441 100644
> --- a/gdb/ui-file.h
> +++ b/gdb/ui-file.h
> @@ -224,7 +224,7 @@ class string_file : public ui_file
>    bool empty () const { return m_string.empty (); }
>    void clear () { return m_string.clear (); }
>  
> -private:
> +protected:
>    /* The internal buffer.  */
>    std::string m_string;
>  
> diff --git a/gdb/ui-out.c b/gdb/ui-out.c
> index defa8f9dfa4..3caf33ddece 100644
> --- a/gdb/ui-out.c
> +++ b/gdb/ui-out.c
> @@ -32,6 +32,9 @@
>  #include <memory>
>  #include <string>
>  
> +/* Current state of newline prefixing for progress update messages.  */
> +prefix_state_t cur_prefix_state = prefix_state_t::NEWLINE_OFF;
> +
>  namespace {
>  
>  /* A header of a ui_out_table.  */
> @@ -871,3 +874,134 @@ ui_out::ui_out (ui_out_flags flags)
>  ui_out::~ui_out ()
>  {
>  }
> +
> +/* See ui-out.h.  */
> +
> +void
> +buffer_group::output_unit::flush () const
> +{
> +  m_stream->puts (m_msg.c_str ());

Maybe we should do:

  if (!m_msg.empty ())
    m_stream->puts (m_msg.c_str ());

I guess it doesn't make much difference, but when we queue up a
wrap_here call we add an empty string.

> +
> +  if (m_wrap_hint >= 0)
> +    m_stream->wrap_here (m_wrap_hint);
> +}
> +
> +/* See ui-out.h.  */
> +
> +void
> +buffer_group::write (const char *buf, long length_buf, ui_file *stream)
> +{
> +  /* Record each line separately.  */
> +  for (size_t prev = 0, cur = 0; cur < length_buf; ++cur)
> +    if (buf[cur] == '\n' || cur == length_buf - 1)
> +      {
> +	std::string msg (buf + prev, cur - prev + 1);
> +
> +	if (m_buffered_output.size () > 0
> +	    && m_buffered_output.back ().m_wrap_hint == -1
> +	    && m_buffered_output.back ().m_stream == stream
> +	    && m_buffered_output.back ().m_msg.size () > 0
> +	    && m_buffered_output.back ().m_msg.back () != '\n')
> +	  m_buffered_output.back ().m_msg.append (msg);
> +	else
> +	  {
> +	    m_buffered_output.emplace_back (msg);
> +	    m_buffered_output.back ().m_stream = stream;
> +	  }
> +	prev = cur + 1;
> +      }
> +}
> +
> +/* See ui-out.h.  */
> +
> +void
> +buffer_group::wrap_here (int indent, ui_file *stream)
> +{
> +  m_buffered_output.emplace_back ("", indent);
> +  m_buffered_output.back ().m_stream = stream;
> +}
> +
> +/* See ui-out.h.  */
> +
> +ui_file *
> +get_unbuffered (ui_file * stream)
> +{
> +  buffering_file *buf = dynamic_cast<buffering_file *> (stream);
> +
> +  if (buf == nullptr)
> +    return stream;
> +
> +  return get_unbuffered (buf->stream ());
> +}
> +
> +buffered_streams::buffered_streams (buffer_group *group, ui_out *uiout)
> +    : m_buffered_stdout (group, gdb_stdout),
> +      m_buffered_stderr (group, gdb_stderr),
> +      m_buffered_stdlog (group, gdb_stdlog),
> +      m_buffered_stdtarg (group, gdb_stdtarg),
> +      m_buffered_stdtargerr (group, gdb_stdtargerr),
> +      m_uiout (uiout)
> +  {
> +    gdb_stdout = &m_buffered_stdout;
> +    gdb_stderr = &m_buffered_stderr;
> +    gdb_stdlog = &m_buffered_stdlog;
> +    gdb_stdtarg = &m_buffered_stdtarg;
> +    gdb_stdtargerr = &m_buffered_stdtargerr;
> +
> +    ui_file *stream = current_uiout->current_stream ();
> +    if (stream != nullptr)
> +      {
> +	m_buffered_current_uiout.emplace (group, stream);
> +	current_uiout->redirect (&(*m_buffered_current_uiout));
> +      }

When I was thinking about this problem, I imagined replacing this
current_uiout code with the code you've added below.  My thinking is
that M_UIOUT is what we are about to pass to the printing routine,
right?  So if we are actually using CURRENT_UIOUT within the printing
routine, then something is going horribly wrong.

Caching CURRENT_UIOUT feels like a work around for possibly broken code
elsewhere in GDB.

Have you tried this patch without the CURRENT_UIOUT buffering?  Only
buffer M_UIOUT?  Hopefully that works fine, but if it throws up some
errors, maybe we should look into those and see if we can fix them.

> +
> +    stream = m_uiout->current_stream ();
> +    if (stream != nullptr && current_uiout != m_uiout)
> +      {
> +	m_buffered_uiout.emplace (group, stream);
> +	m_uiout->redirect (&(*m_buffered_uiout));
> +      }
> +
> +    m_buffers_in_place = true;
> +  };
> +
> +/* See ui-out.h.  */
> +
> +void
> +buffered_streams::remove_buffers ()
> +  {
> +    if (!m_buffers_in_place)
> +      return;
> +
> +    m_buffers_in_place = false;
> +
> +    gdb_stdout = m_buffered_stdout.stream ();
> +    gdb_stderr = m_buffered_stderr.stream ();
> +    gdb_stdlog = m_buffered_stdlog.stream ();
> +    gdb_stdtarg = m_buffered_stdtarg.stream ();
> +    gdb_stdtargerr = m_buffered_stdtargerr.stream ();
> +
> +    if (m_buffered_current_uiout.has_value ())
> +      current_uiout->redirect (nullptr);
> +
> +    if (m_buffered_uiout.has_value ())
> +      m_uiout->redirect (nullptr);
> +  }
> +
> +buffer_group::buffer_group (ui_out *uiout)
> +  : m_buffered_streams (new buffered_streams (this, uiout))
> +{ /* Nothing.  */ }
> +
> +buffer_group::~buffer_group ()
> +{ /* Nothing.  */ }
> +
> +/* See ui-out.h.  */
> +
> +void
> +buffer_group::flush () const
> +{
> +  m_buffered_streams->remove_buffers ();
> +
> +  for (const output_unit &ou : m_buffered_output)
> +    ou.flush ();
> +}
> diff --git a/gdb/ui-out.h b/gdb/ui-out.h
> index 07567a1df35..45d8007587b 100644
> --- a/gdb/ui-out.h
> +++ b/gdb/ui-out.h
> @@ -278,6 +278,9 @@ class ui_out
>       escapes.  */
>    virtual bool can_emit_style_escape () const = 0;
>  
> +  /* Return the ui_file currently used for output.  */
> +  virtual ui_file *current_stream () const = 0;
> +
>    /* An object that starts and finishes displaying progress updates.  */
>    class progress_update
>    {
> @@ -293,6 +296,21 @@ class ui_out
>        BAR
>      };
>  
> +    /* Used to communicate the status of a newline prefix for the next progress
> +       update message.  */
> +    enum prefix_state
> +    {
> +      /* Do not modify the next progress update message.  */
> +      NEWLINE_OFF,
> +
> +      /* The next progress update message should include a newline prefix.  */
> +      NEWLINE_NEEDED,
> +
> +      /* A newline prefix was included in a debuginfod progress update
> +	 message.  */
> +      NEWLINE_PRINTED
> +    };
> +
>      /* SHOULD_PRINT indicates whether something should be printed for a tty.  */
>      progress_update ()
>      {
> @@ -390,6 +408,11 @@ class ui_out
>    ui_out_level *current_level () const;
>  };
>  
> +typedef ui_out::progress_update::prefix_state prefix_state_t;
> +
> +/* Current state of the newline prefix.  */
> +extern prefix_state_t cur_prefix_state;
> +
>  /* Start a new tuple or list on construction, and end it on
>     destruction.  Normally this is used via the typedefs
>     ui_out_emit_tuple and ui_out_emit_list.  */
> @@ -470,4 +493,181 @@ class ui_out_redirect_pop
>    struct ui_out *m_uiout;
>  };
>  
> +struct buffered_streams;
> +
> +/* Organizes writes to a collection of buffered output streams
> +   so that when flushed, output is written to all streams in
> +   chronological order.  */
> +
> +struct buffer_group
> +{
> +  buffer_group (ui_out *uiout);
> +
> +  ~buffer_group ();
> +
> +  /* Flush all buffered writes to the underlying output streams.  */
> +  void flush () const;
> +
> +  /* Record contents of BUF and associate it with STREAM.  */
> +  void write (const char *buf, long length_buf, ui_file *stream);
> +
> +  /* Record a wrap_here and associate it with STREAM.  */
> +  void wrap_here (int indent, ui_file *stream);
> +
> +private:
> +
> +  struct output_unit
> +  {
> +    output_unit (std::string msg, int wrap_hint = -1)
> +      : m_msg (msg), m_wrap_hint (wrap_hint)
> +    {}
> +
> +    /* Write contents of this output_unit to the underlying stream.  */
> +    void flush () const;
> +
> +    /* Underlying stream for which this output unit will be written to.  */
> +    ui_file *m_stream;
> +
> +    /* String to be written to underlying buffer.  */
> +    std::string m_msg;
> +
> +    /* Argument to wrap_here.  -1 indicates no wrap.  Used to call wrap_here
> +       at appropriate times during flush.  */
> +    int m_wrap_hint;
> +  };
> +
> +  /* Output_units to be written to buffered output streams.  */
> +  std::vector<output_unit> m_buffered_output;
> +
> +  /* Buffered output streams.  */
> +  std::unique_ptr<buffered_streams> m_buffered_streams;
> +};
> +
> +/* If FILE is a buffering_file, return it's underlying stream.  */
> +
> +extern ui_file *get_unbuffered (ui_file *file);
> +
> +/* Buffer output to gdb_stdout and gdb_stderr for the duration of FUNC.  */
> +
> +template<typename F, typename... Arg>
> +void
> +do_with_buffered_output (F func, ui_out *uiout, Arg... args)
> +{
> +  buffer_group g (uiout);
> +
> +  try
> +    {
> +      func (uiout, std::forward<Arg> (args)...);
> +    }
> +  catch (gdb_exception &ex)
> +    {
> +      /* Ideally flush would be called in the destructor of buffer_group,
> +	 however flushing might cause an exception to be thrown.  Catch it
> +	 and ensure the first exception propagates.  */
> +      try
> +	{
> +	  g.flush ();
> +	}
> +      catch (const gdb_exception &)
> +	{
> +	}
> +
> +      throw_exception (std::move (ex));
> +    }
> +
> +  /* Try was successful.  Let any further exceptions propagate.  */
> +  g.flush ();
> +}
> +
> +/* Accumulate writes to an underlying ui_file.  Output to the
> +   underlying file is deferred until required.  */
> +
> +struct buffering_file : public ui_file
> +{
> +  buffering_file (buffer_group *group, ui_file *stream)
> +    : m_group (group),
> +      m_stream (stream)
> +  { /* Nothing.  */ }
> +
> +  /* Return the underlying output stream.  */
> +  ui_file *stream () const
> +  {
> +    return m_stream;
> +  }
> +
> +  /* Record the contents of BUF.  */
> +  void write (const char *buf, long length_buf) override
> +  {
> +    m_group->write (buf, length_buf, m_stream);
> +  }
> +
> +  /* Record a wrap_here call with argument INDENT.  */
> +  void wrap_here (int indent) override
> +  {
> +    m_group->wrap_here (indent, m_stream);
> +  }
> +
> +  /* Return true if the underlying stream is a tty.  */
> +  bool isatty () override
> +  {
> +    return m_stream->isatty ();
> +  }
> +
> +  /* Return true if ANSI escapes can be used on the underlying stream.  */
> +  bool can_emit_style_escape () override
> +  {
> +    return m_stream->can_emit_style_escape ();
> +  }
> +
> +  /* Flush the underlying output stream.  */
> +  void flush () override
> +  {
> +    return m_stream->flush ();
> +  }

This doesn't seem right.  Some caller is going to perform a series of
write, wrap_here, and flush calls, and we should be queuing them up,
then replaying them later, right?

We queue up the write and wrap_here calls, but the flush calls we send
through immediately.

I'm not sure we actually need to add the flush as a separate output_unit
in the buffer_group though, maybe all that's needed is a single bool
flag per-stream somewhere?  Then in buffer_group::flush, we can somehow
arrange to call flush on those streams that have a queued flush pending?

Thanks,
Andrew

> +
> +private:
> +
> +  /* Coordinates buffering across multiple buffering_files.  */
> +  buffer_group *m_group;
> +
> +  /* The underlying output stream.  */
> +  ui_file *m_stream;
> +};
> +
> +/* Attaches and detaches buffers for each of the gdb_std* streams.  */
> +
> +struct buffered_streams
> +{
> +  buffered_streams (buffer_group *group, ui_out *uiout);
> +
> +  ~buffered_streams ()
> +  {
> +    this->remove_buffers ();
> +  }
> +
> +  /* Remove buffering_files from all underlying streams.  */
> +  void remove_buffers ();
> +
> +private:
> +
> +  /* True if buffers are still attached to each underlying output stream.  */
> +  bool m_buffers_in_place;
> +
> +  /* Buffers for each gdb_std* output stream.  */
> +  buffering_file m_buffered_stdout;
> +  buffering_file m_buffered_stderr;
> +  buffering_file m_buffered_stdlog;
> +  buffering_file m_buffered_stdtarg;
> +  buffering_file m_buffered_stdtargerr;
> +
> +  /* Buffer for current_uiout's output stream.  */
> +  gdb::optional<buffering_file> m_buffered_current_uiout;
> +
> +  /* Additional ui_out being buffered.  */
> +  ui_out *m_uiout;
> +
> +  /* Buffer for m_uiout's output stream.  */
> +  gdb::optional<buffering_file> m_buffered_uiout;
> +};
> +
>  #endif /* UI_OUT_H */
> -- 
> 2.41.0
  

On Tue, Oct 24, 2023 at 7:23 AM Andrew Burgess <aburgess@redhat.com> wrote:
>
> Unless I'm missing something, none of this cur_prefix_state stuff can
> trigger after this commit; the cur_prefix_state starts as
> prefix_state_t::NEWLINE_OFF and can never change from that state.
>
> I know this changes after later patches in this series, but it feels
> like this work has ended up in this patch by mistake.
>
> Could we remove these changes from this commit and push them into a
> later commit in this series?

Moved to patch 4/4.

> > +void
> > +buffer_group::output_unit::flush () const
> > +{
> > +  m_stream->puts (m_msg.c_str ());
>
> Maybe we should do:
>
>   if (!m_msg.empty ())
>     m_stream->puts (m_msg.c_str ());
>
> I guess it doesn't make much difference, but when we queue up a
> wrap_here call we add an empty string.

Done.

> > +buffered_streams::buffered_streams (buffer_group *group, ui_out *uiout)
> > +    : m_buffered_stdout (group, gdb_stdout),
> > +      m_buffered_stderr (group, gdb_stderr),
> > +      m_buffered_stdlog (group, gdb_stdlog),
> > +      m_buffered_stdtarg (group, gdb_stdtarg),
> > +      m_buffered_stdtargerr (group, gdb_stdtargerr),
> > +      m_uiout (uiout)
> > +  {
> > +    gdb_stdout = &m_buffered_stdout;
> > +    gdb_stderr = &m_buffered_stderr;
> > +    gdb_stdlog = &m_buffered_stdlog;
> > +    gdb_stdtarg = &m_buffered_stdtarg;
> > +    gdb_stdtargerr = &m_buffered_stdtargerr;
> > +
> > +    ui_file *stream = current_uiout->current_stream ();
> > +    if (stream != nullptr)
> > +      {
> > +     m_buffered_current_uiout.emplace (group, stream);
> > +     current_uiout->redirect (&(*m_buffered_current_uiout));
> > +      }
>
> When I was thinking about this problem, I imagined replacing this
> current_uiout code with the code you've added below.  My thinking is
> that M_UIOUT is what we are about to pass to the printing routine,
> right?  So if we are actually using CURRENT_UIOUT within the printing
> routine, then something is going horribly wrong.
>
> Caching CURRENT_UIOUT feels like a work around for possibly broken code
> elsewhere in GDB.
>
> Have you tried this patch without the CURRENT_UIOUT buffering?  Only
> buffer M_UIOUT?  Hopefully that works fine, but if it throws up some
> errors, maybe we should look into those and see if we can fix them.

It does not work without buffering both CURRENT_UIOUT and M_UIOUT but
I don't think this is an indication that something has gone wrong.

Before this patch, some of the functions we now apply output buffering
to (via do_with_buffered_output) would set CURRENT_UIOUT to a local
variable and print to that CURRENT_UIOUT alias for their duration.
Other buffered functions take a uiout argument that may or may not
be the CURRENT_UIOUT.

I think the current approach of buffering both CURRENT_UIOUT
and M_UIOUT is a simple way to cover all of these cases without
having to tweak very much within the buffered functions.

>
> > +
> > +    stream = m_uiout->current_stream ();
> > +    if (stream != nullptr && current_uiout != m_uiout)
> > +      {
> > +     m_buffered_uiout.emplace (group, stream);
> > +     m_uiout->redirect (&(*m_buffered_uiout));
> > +      }
> > +
> > +    m_buffers_in_place = true;
> > +  };
> > +
> > +/* See ui-out.h.  */
> > +
> > +void
> > +buffered_streams::remove_buffers ()
> > +  {
> > +    if (!m_buffers_in_place)
> > +      return;
> > +
> > +    m_buffers_in_place = false;
> > +
> > +    gdb_stdout = m_buffered_stdout.stream ();
> > +    gdb_stderr = m_buffered_stderr.stream ();
> > +    gdb_stdlog = m_buffered_stdlog.stream ();
> > +    gdb_stdtarg = m_buffered_stdtarg.stream ();
> > +    gdb_stdtargerr = m_buffered_stdtargerr.stream ();
> > +
> > +    if (m_buffered_current_uiout.has_value ())
> > +      current_uiout->redirect (nullptr);
> > +
> > +    if (m_buffered_uiout.has_value ())
> > +      m_uiout->redirect (nullptr);
> > +  }
> > +
> > +buffer_group::buffer_group (ui_out *uiout)
> > +  : m_buffered_streams (new buffered_streams (this, uiout))
> > +{ /* Nothing.  */ }
> > +
> > +buffer_group::~buffer_group ()
> > +{ /* Nothing.  */ }
> > +
> > +/* See ui-out.h.  */
> > +
> > +void
> > +buffer_group::flush () const
> > +{
> > +  m_buffered_streams->remove_buffers ();
> > +
> > +  for (const output_unit &ou : m_buffered_output)
> > +    ou.flush ();
> > +}
> > diff --git a/gdb/ui-out.h b/gdb/ui-out.h
> > index 07567a1df35..45d8007587b 100644
> > --- a/gdb/ui-out.h
> > +++ b/gdb/ui-out.h
> > @@ -278,6 +278,9 @@ class ui_out
> >       escapes.  */
> >    virtual bool can_emit_style_escape () const = 0;
> >
> > +  /* Return the ui_file currently used for output.  */
> > +  virtual ui_file *current_stream () const = 0;
> > +
> >    /* An object that starts and finishes displaying progress updates.  */
> >    class progress_update
> >    {
> > @@ -293,6 +296,21 @@ class ui_out
> >        BAR
> >      };
> >
> > +    /* Used to communicate the status of a newline prefix for the next progress
> > +       update message.  */
> > +    enum prefix_state
> > +    {
> > +      /* Do not modify the next progress update message.  */
> > +      NEWLINE_OFF,
> > +
> > +      /* The next progress update message should include a newline prefix.  */
> > +      NEWLINE_NEEDED,
> > +
> > +      /* A newline prefix was included in a debuginfod progress update
> > +      message.  */
> > +      NEWLINE_PRINTED
> > +    };
> > +
> >      /* SHOULD_PRINT indicates whether something should be printed for a tty.  */
> >      progress_update ()
> >      {
> > @@ -390,6 +408,11 @@ class ui_out
> >    ui_out_level *current_level () const;
> >  };
> >
> > +typedef ui_out::progress_update::prefix_state prefix_state_t;
> > +
> > +/* Current state of the newline prefix.  */
> > +extern prefix_state_t cur_prefix_state;
> > +
> >  /* Start a new tuple or list on construction, and end it on
> >     destruction.  Normally this is used via the typedefs
> >     ui_out_emit_tuple and ui_out_emit_list.  */
> > @@ -470,4 +493,181 @@ class ui_out_redirect_pop
> >    struct ui_out *m_uiout;
> >  };
> >
> > +struct buffered_streams;
> > +
> > +/* Organizes writes to a collection of buffered output streams
> > +   so that when flushed, output is written to all streams in
> > +   chronological order.  */
> > +
> > +struct buffer_group
> > +{
> > +  buffer_group (ui_out *uiout);
> > +
> > +  ~buffer_group ();
> > +
> > +  /* Flush all buffered writes to the underlying output streams.  */
> > +  void flush () const;
> > +
> > +  /* Record contents of BUF and associate it with STREAM.  */
> > +  void write (const char *buf, long length_buf, ui_file *stream);
> > +
> > +  /* Record a wrap_here and associate it with STREAM.  */
> > +  void wrap_here (int indent, ui_file *stream);
> > +
> > +private:
> > +
> > +  struct output_unit
> > +  {
> > +    output_unit (std::string msg, int wrap_hint = -1)
> > +      : m_msg (msg), m_wrap_hint (wrap_hint)
> > +    {}
> > +
> > +    /* Write contents of this output_unit to the underlying stream.  */
> > +    void flush () const;
> > +
> > +    /* Underlying stream for which this output unit will be written to.  */
> > +    ui_file *m_stream;
> > +
> > +    /* String to be written to underlying buffer.  */
> > +    std::string m_msg;
> > +
> > +    /* Argument to wrap_here.  -1 indicates no wrap.  Used to call wrap_here
> > +       at appropriate times during flush.  */
> > +    int m_wrap_hint;
> > +  };
> > +
> > +  /* Output_units to be written to buffered output streams.  */
> > +  std::vector<output_unit> m_buffered_output;
> > +
> > +  /* Buffered output streams.  */
> > +  std::unique_ptr<buffered_streams> m_buffered_streams;
> > +};
> > +
> > +/* If FILE is a buffering_file, return it's underlying stream.  */
> > +
> > +extern ui_file *get_unbuffered (ui_file *file);
> > +
> > +/* Buffer output to gdb_stdout and gdb_stderr for the duration of FUNC.  */
> > +
> > +template<typename F, typename... Arg>
> > +void
> > +do_with_buffered_output (F func, ui_out *uiout, Arg... args)
> > +{
> > +  buffer_group g (uiout);
> > +
> > +  try
> > +    {
> > +      func (uiout, std::forward<Arg> (args)...);
> > +    }
> > +  catch (gdb_exception &ex)
> > +    {
> > +      /* Ideally flush would be called in the destructor of buffer_group,
> > +      however flushing might cause an exception to be thrown.  Catch it
> > +      and ensure the first exception propagates.  */
> > +      try
> > +     {
> > +       g.flush ();
> > +     }
> > +      catch (const gdb_exception &)
> > +     {
> > +     }
> > +
> > +      throw_exception (std::move (ex));
> > +    }
> > +
> > +  /* Try was successful.  Let any further exceptions propagate.  */
> > +  g.flush ();
> > +}
> > +
> > +/* Accumulate writes to an underlying ui_file.  Output to the
> > +   underlying file is deferred until required.  */
> > +
> > +struct buffering_file : public ui_file
> > +{
> > +  buffering_file (buffer_group *group, ui_file *stream)
> > +    : m_group (group),
> > +      m_stream (stream)
> > +  { /* Nothing.  */ }
> > +
> > +  /* Return the underlying output stream.  */
> > +  ui_file *stream () const
> > +  {
> > +    return m_stream;
> > +  }
> > +
> > +  /* Record the contents of BUF.  */
> > +  void write (const char *buf, long length_buf) override
> > +  {
> > +    m_group->write (buf, length_buf, m_stream);
> > +  }
> > +
> > +  /* Record a wrap_here call with argument INDENT.  */
> > +  void wrap_here (int indent) override
> > +  {
> > +    m_group->wrap_here (indent, m_stream);
> > +  }
> > +
> > +  /* Return true if the underlying stream is a tty.  */
> > +  bool isatty () override
> > +  {
> > +    return m_stream->isatty ();
> > +  }
> > +
> > +  /* Return true if ANSI escapes can be used on the underlying stream.  */
> > +  bool can_emit_style_escape () override
> > +  {
> > +    return m_stream->can_emit_style_escape ();
> > +  }
> > +
> > +  /* Flush the underlying output stream.  */
> > +  void flush () override
> > +  {
> > +    return m_stream->flush ();
> > +  }
>
> This doesn't seem right.  Some caller is going to perform a series of
> write, wrap_here, and flush calls, and we should be queuing them up,
> then replaying them later, right?
>
> We queue up the write and wrap_here calls, but the flush calls we send
> through immediately.
>
> I'm not sure we actually need to add the flush as a separate output_unit
> in the buffer_group though, maybe all that's needed is a single bool
> flag per-stream somewhere?  Then in buffer_group::flush, we can somehow
> arrange to call flush on those streams that have a queued flush pending?

Fixed.  I ended up recording flush with a separate output_unit because
this functionality fits well within the design of output_unit.  Plus it
ensures that the flush occurs exactly at the intended points in the output.

The remaining patches in this series have been reposted here with these
changes:
https://sourceware.org/pipermail/gdb-patches/2023-October/203589.html

Aaron