Re: [PATCH 5/5] Eliminate make_cleanup_ui_file_delete / make ui_file a class hierarchy

Pedro Alves
2017-01-23T17:17:51Z

On 01/23/2017 04:58 PM, Pedro Alves wrote:

> Now, looking again with fresh eyes, I now believe that the
> only reason this assert triggers, is because the implementation
> of that sequence of commands for MI is plain buggy. If
> you do it with current master, GDB crashes!
>
> Program received signal SIGSEGV, Segmentation fault.
> 0x00000000008dd7bc in gdb_flush (file=0x2a097f0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.c:194
> 194 file->to_flush (file);
> (top-gdb) bt
> #0 0x00000000008dd7bc in gdb_flush(ui_file*) (file=0x2a097f0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.c:194
> #1 0x00000000007b5f34 in gdb_wait_for_event(int) (block=0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:752
> #2 0x00000000007b52b6 in gdb_do_one_event() () at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:322
> #3 0x00000000007b5362 in start_event_loop() () at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:371
> #4 0x000000000082704a in captured_command_loop(void*) (data=0x0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:325
> #5 0x00000000007b8d7c in catch_errors(int (*)(void*), void*, char*, return_mask) (func=0x827008 <captured_command_loop(void*)>, func_args=0x0, errstring=0x11dee51 "", mask=RETURN_MASK_ALL) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/exceptions.c:236
> #6 0x000000000082839b in captured_main(void*) (data=0x7fffffffd820) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:1148
> During symbol reading, cannot get low and high bounds for subprogram DIE at 24065.
> #7 0x00000000008283c4 in gdb_main(captured_main_args*) (args=0x7fffffffd820) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:1158
> #8 0x0000000000412d4d in main(int, char**) (argc=4, argv=0x7fffffffd928) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/gdb.c:32
>
> So it looks like the assert is catching a problem earlier.
> Without the assert, gdb continues on with bogus state
> and eventually crashes.
>
> Going back to my patch, in the bad case, we get to:
>
> void
> mi_ui_out::put (ui_file *stream)
> {
> ui_file *outstream = m_streams.back ();
>
> outstream->write_buffer_on (*stream);
> outstream->rewind ();
> }
>
> with STREAM and OUTSTREAM pointing to the same thing...
>
> This happens because we try to handle "set logging
> redirect on" while logging is enabled:
>
> https://sourceware.org/ml/gdb-patches/2010-08/msg00202.html
>
> but get it wrong for MI. (Strictly speaking, MI logging support
> was added after that patch, so it was the MI logging patch
> that missed this.)
> I find that code to handle on-the-fly redirect quite hard to
> follow and reason about, along with the interp set_logging mechanism
> and how CLI and MI hook into all this. I think the fix here should
> simply be to stop trying to handle changing logging redirect on the fly,
> and require turning logging off and on, like Jan's original patch
> was proposing. I'll post a patch for that as follow up, to make
> it clearer what I mean.
>

I mean the patch below. Applies on top of the series, not master,
just because that was simpler for me, but it could be rebased on
current master.

From 158171db401ba0fa1dd1ac0ac059dd73714942b8 Mon Sep 17 00:00:00 2001
From: Pedro Alves <palves@redhat.com>
Date: Mon, 23 Jan 2017 14:27:07 +0000
Subject: [PATCH] Fix "-gdb-set logging redirect on" crash

By not handling "logging redirect on" on the fly.

Code for handling "logging redirect on" on the fly was added here:

https://sourceware.org/ml/gdb-patches/2010-08/msg00202.html

Meanwhile, MI gained support for logging, but flipping redirect on on
the fly was not considered, and the result is that this sequence of
events crashes GDB:

-gdb-set logging on
-gdb-set logging redirect on

Program received signal SIGSEGV, Segmentation fault.
0x00000000008dd7bc in gdb_flush (file=0x2a097f0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.c:194
194 file->to_flush (file);
(top-gdb) bt
#0 0x00000000008dd7bc in gdb_flush(ui_file*) (file=0x2a097f0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.c:194
#1 0x00000000007b5f34 in gdb_wait_for_event(int) (block=0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:752
#2 0x00000000007b52b6 in gdb_do_one_event() () at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:322
#3 0x00000000007b5362 in start_event_loop() () at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:371
#4 0x000000000082704a in captured_command_loop(void*) (data=0x0) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:325
#5 0x00000000007b8d7c in catch_errors(int (*)(void*), void*, char*, return_mask) (func=0x827008 <captured_command_loop(void*)>, func_args=0x0, errstring=0x11dee51 "", mask=RETURN_MASK_ALL) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/exceptions.c:236
#6 0x000000000082839b in captured_main(void*) (data=0x7fffffffd820) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:1148
During symbol reading, cannot get low and high bounds for subprogram DIE at 24065.
#7 0x00000000008283c4 in gdb_main(captured_main_args*) (args=0x7fffffffd820) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:1158
#8 0x0000000000412d4d in main(int, char**) (argc=4, argv=0x7fffffffd928) at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/gdb.c:32

The handling of redirect on the fly is not really a use case we need
to handle, IMO, its inconsistent (other "set logging foo" commands
aren't handled on the fly), and complicates the code significantly.
Instead of complicating it further for MI, go back to the original
idea of warning, only:

https://sourceware.org/ml/gdb-patches/2010-08/msg00083.html

New test included.

gdb/ChangeLog:
2017-01-23 Pedro Alves <palves@redhat.com>

* cli/cli-logging.c (maybe_warn_already_logging): New factored out
from ...
(set_logging_overwrite): ... here.
(logging_no_redirect_file): Delete.
(set_logging_redirect): Don't handle redirection on the fly.
Instead warn that "logging off" / "logging on" is necessary.
(pop_output_files): Delete references to logging_no_redirect_file.
(show_logging_command): Always speak in terms of what will happen
once logging is reenabled.

gdb/testsuite/ChangeLog:
2017-01-23 Pedro Alves <palves@redhat.com>

* gdb.mi/mi-logging.exp: Add "redirect while already logging"
tests.
---
gdb/cli/cli-logging.c | 104 +++++-------------------------------
gdb/testsuite/gdb.mi/mi-logging.exp | 14 +++++
2 files changed, 28 insertions(+), 90 deletions(-)

diff --git a/gdb/cli/cli-logging.c b/gdb/cli/cli-logging.c
index f9a845e..9de55f0 100644
--- a/gdb/cli/cli-logging.c
+++ b/gdb/cli/cli-logging.c
@@ -47,7 +47,7 @@ show_logging_filename (struct ui_file *file, int from_tty,
static int logging_overwrite;

static void
-set_logging_overwrite (char *args, int from_tty, struct cmd_list_element *c)
+maybe_warn_already_logging ()
{
if (saved_filename)
warning (_("Currently logging to %s. Turn the logging off and on to "
@@ -55,6 +55,12 @@ set_logging_overwrite (char *args, int from_tty, struct cmd_list_element *c)
}

static void
+set_logging_overwrite (char *args, int from_tty, struct cmd_list_element *c)
+{
+ maybe_warn_already_logging ();
+}
+
+static void
show_logging_overwrite (struct ui_file *file, int from_tty,
struct cmd_list_element *c, const char *value)
{
@@ -67,70 +73,10 @@ show_logging_overwrite (struct ui_file *file, int from_tty,
/* Value as configured by the user. */
static int logging_redirect;

-/* The on-disk file in use if logging is currently active together
- with redirection turned off (and therefore using tee_file_new).
- For active logging with redirection the on-disk file is directly in
- GDB_STDOUT and this variable is NULL. */
-static struct ui_file *logging_no_redirect_file;
-
static void
set_logging_redirect (char *args, int from_tty, struct cmd_list_element *c)
{
- ui_file_up destroy_old_stdout;
- struct ui_file *output, *new_logging_no_redirect_file;
- struct ui_out *uiout = current_uiout;
-
- if (saved_filename == NULL
- || (logging_redirect != 0 && logging_no_redirect_file == NULL)
- || (logging_redirect == 0 && logging_no_redirect_file != NULL))
- return;
-
- if (logging_redirect != 0)
- {
- gdb_assert (logging_no_redirect_file != NULL);
-
- /* ui_out_redirect still has not been called for next
- gdb_stdout. */
- destroy_old_stdout.reset (gdb_stdout);
-
- output = logging_no_redirect_file;
- new_logging_no_redirect_file = NULL;
-
- if (from_tty)
- fprintf_unfiltered (saved_output.out, "Redirecting output to %s.\n",
- logging_filename);
- }
- else
- {
- gdb_assert (logging_no_redirect_file == NULL);
- output = new tee_file (saved_output.out, 0, gdb_stdout, 0);
- new_logging_no_redirect_file = gdb_stdout;
-
- if (from_tty)
- fprintf_unfiltered (saved_output.out, "Copying output to %s.\n",
- logging_filename);
- }
-
- /* Give the current interpreter a chance to do anything special that
- it might need for logging, such as updating other channels. */
- if (current_interp_set_logging (1, output, NULL) == 0)
- {
- gdb_stdout = output;
- gdb_stdlog = output;
- gdb_stderr = output;
- gdb_stdtarg = output;
- gdb_stdtargerr = output;
- }
-
- logging_no_redirect_file = new_logging_no_redirect_file;
-
- /* There is a former output pushed on the ui_out_redirect stack. We
- want to replace it by OUTPUT so we must pop the former value
- first. Ideally, we should either do both the pop and push or do
- neither of them. */
-
- uiout->redirect (NULL);
- uiout->redirect (output);
+ maybe_warn_already_logging ();
}

static void
@@ -144,12 +90,6 @@ show_logging_redirect (struct ui_file *file, int from_tty,
static void
pop_output_files (void)
{
- if (logging_no_redirect_file)
- {
- delete logging_no_redirect_file;
- logging_no_redirect_file = NULL;
- }
-
if (current_interp_set_logging (0, NULL, NULL) == 0)
{
/* Only delete one of the files -- they are all set to the same
@@ -203,16 +143,10 @@ handle_redirections (int from_tty)
if (from_tty)
fprintf_unfiltered (gdb_stdout, "Copying output to %s.\n",
logging_filename);
- logging_no_redirect_file = no_redirect_file;
- }
- else
- {
- gdb_assert (logging_no_redirect_file == NULL);
-
- if (from_tty)
- fprintf_unfiltered (gdb_stdout, "Redirecting output to %s.\n",
- logging_filename);
}
+ else if (from_tty)
+ fprintf_unfiltered (gdb_stdout, "Redirecting output to %s.\n",
+ logging_filename);

log.release ();

@@ -290,20 +224,10 @@ show_logging_command (char *args, int from_tty)
else
printf_unfiltered (_("Logs will be appended to the log file.\n"));

- if (saved_filename)
- {
- if (logging_redirect)
- printf_unfiltered (_("Output is being sent only to the log file.\n"));
- else
- printf_unfiltered (_("Output is being logged and displayed.\n"));
- }
+ if (logging_redirect)
+ printf_unfiltered (_("Output will be sent only to the log file.\n"));
else
- {
- if (logging_redirect)
- printf_unfiltered (_("Output will be sent only to the log file.\n"));
- else
- printf_unfiltered (_("Output will be logged and displayed.\n"));
- }
+ printf_unfiltered (_("Output will be logged and displayed.\n"));
}

/* Provide a prototype to silence -Wmissing-prototypes. */
diff --git a/gdb/testsuite/gdb.mi/mi-logging.exp b/gdb/testsuite/gdb.mi/mi-logging.exp
index 788a9bf..07eaff9 100644
--- a/gdb/testsuite/gdb.mi/mi-logging.exp
+++ b/gdb/testsuite/gdb.mi/mi-logging.exp
@@ -82,6 +82,20 @@ if [regexp "1001\\^done\[\r\n\]+$mi_log_prompt.*1002\\^running\[\r\n\]+\\*runnin
fail "redirect log file contents"
}

+# Now try enabling a redirect while GDB is already logging. This used
+# to crash GDB.
+with_test_prefix "redirect while already logging" {
+ mi_gdb_test "-gdb-set logging redirect off" ".*" \
+ "logging redirect off"
+ mi_gdb_test "-gdb-set logging on" ".*" \
+ "logging on"
+ mi_gdb_test "-gdb-set logging redirect on" \
+ ".*warning: Currently logging .*Turn the logging off and on to make the new setting effective.*" \
+ "logging redirect on"
+ mi_gdb_test "-gdb-set logging off" ".*" \
+ "logging off"
+}
+
mi_gdb_exit

remote_file host delete $milogfile
--
2.5.5