This is the mail archive of the gdb-patches@sourceware.org mailing list for the GDB project.

Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]
Other format: [Raw text]

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

On 2017-01-23 11:58, Pedro Alves wrote:

I'm not sure about the implications, but instinctively I would've made
rewind in the base class throw an exception by default, instead of
making the derived types throw one if they don't support rewind.
Actually, except for the null_file, I don't really see when you would
want rewind to be a no-op.  If the rewind call returns but does not
actually rewind, isn't it lying to the client code?
Yes, indeed it's a lie, but it's not really a new lie. :-) It's similar to 
how the existing code works.  Before the patch, write_buffer_on doesn't
exist, but what it replaces, the "put" callback, behaved similarly -- only 
mem_fileopen, TUI and guile ui-files implement the put method,
all others leave it set to null_file_put (the default).
"write/write_buffer_on", like "put" were only meant for
locally buffered files (like mem_fileopen/tui_sfileopen).
ioscm_file_port might have only implemented put because the
method was there in ui_file to implement.
It's a bit of a bogus design, but it didn't seem easy to fix.
The asserts were me trying to figure out where are the calls to
write_buffer_on / rewind coming from.  I meant to come back to this
before posting, but then ended up posting this sooner than I
thought, and forgot to remove the asserts.  Anyway, I took another
look at all this today, and I have a proposal.

After my patch, the ui_file::write_buffer_on method is only
used here, in the MI's ui_out:

void
mi_ui_out::put (ui_file *stream)
{
  ui_file *outstream = m_streams.back ();

  outstream->write_buffer_on (*stream);
  outstream->rewind ();
}

When I was originally writing this series a couple months ago, I tried
to come up with a way to get here with the m_streams vector containing
some ui_file at the top of the stack that is not the ui_out's original
stream_file.  And I think I had found some, around enabling
MI logging, and so to preserve behavior, I was planning on leaving
both the write_buffer_on and rewind methods as no-ops for
most ui_files, thinking that to fix this we're need a larger
redesign to the CLI/MI logging code (which looks kind of horrible)
that would be better done on top.
I have looked at the MI logging code and I am not sure I understand it. Here's what I think I got, tell me if I'm completely lost:
In the normal case, mi_ui_out accumulates the output bytes in a string_file. Only when the command execution is complete does captured_mi_execute_command dump the accumulated output in the real output stream with: 

  mi_out_put (uiout, mi->raw_stdout);
Presumably, this is so that we don't send part of an MI response in case of errors. If mi_ui_out wrote directly in the real output stream, it wouldn't be able to cancel/rewind it if there's an error. Hence the need for a rewind/clear method on string_file.
When we turn basic logging on (-gdb-set logging on), handle_redirections prepares a nice little tee ui_file to redirect the output stream to an on-disk file, and passes it to current_interp_set_logging. However, that doesn't work for MI, as it would break the buffering scheme that allows it to cancel some previous output. So it deletes that tee file and creates its own, with which it overrides raw_stdout, which is the output stream used to dump the response once the command execution is complete. So it's when the command response is dumped, that it goes through the tee.
"-gdb-set logging redirect on", would be similar, but it just installs the log file in raw_stdout instead of a tee. 


I redid the experiment / investigation here, and it looks
the only way to reach that method with 'outstream' being something
other than the ui_out's original string_file, is with this
this sequence of MI commands:

 -gdb-set logging on
 -gdb-set logging redirect on
Indeed, at the end of set_logging_redirect, it uses uiout->redirect directly, which puts either a tee_file or stdio_file in mi_ui_out's streams, and breaks all of MI's assumption to find a string_file there when executing a command.
Your follow-up patch prevents changing logging settings while logging is active. And it allows to simply delete that code/case. Did I get it somewhat right? It's still very fuzzy in my head, I can tell that the new code seems saner than what was there. 


This reaches mi_ui_out::put with 'outstream' being a
stdio_file, and triggers the new assertion in stdio_file:

   void rewind () override
   { gdb_assert_not_reached ("can't rewind a stdio file"); }

 #0  0x00000000007ad1b4 in internal_error(char const*, int, char
const*, ...) (file=0x1145b50
"/home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.h", line=190,
fmt=0x1145b44 "%s: %s") at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/common/errors.c:54
 #1  0x0000000000639b77 in stdio_file::rewind() (this=0x335d7e0) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/ui-file.h:190
 #2  0x0000000000634ee4 in mi_ui_out::put(ui_file*) (this=0x2a010e0,
stream=0x335d7e0)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-out.c:255
 #3  0x000000000063519f in mi_out_put(ui_out*, ui_file*)
(uiout=0x2a010e0, stream=0x335d7e0)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-out.c:314
 #4  0x0000000000631b45 in captured_mi_execute_command(ui_out*,
mi_parse*) (uiout=0x2a010e0, context=0x335d2e0)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-main.c:2007
 #5  0x000000000063203d in mi_execute_command(char const*, int)
(cmd=0x335d370 "-gdb-set logging redirect on", from_tty=1)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-main.c:2157
 #6  0x000000000062b0f4 in mi_execute_command_wrapper(char const*)
(cmd=0x335d370 "-gdb-set logging redirect on")
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-interp.c:289
 #7  0x000000000062b180 in mi_execute_command_input_handler(char*)
(cmd=0x335d370 "-gdb-set logging redirect on")
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/mi/mi-interp.c:319
 #8  0x00000000007b8e37 in gdb_readline_no_editing_callback(void*)
(client_data=0x2366b10)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-top.c:855
 #9  0x00000000007b87a7 in stdin_event_handler(int, void*) (error=0,
client_data=0x2366b10)
     at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-top.c:518
 #10 0x00000000007b6dcc in handle_file_event(file_handler*, int)
(file_ptr=0x2e4fc90, ready_mask=1)
    at /home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:733
 #11 0x00000000007b736f in gdb_wait_for_event(int) (block=1) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:859
 #12 0x00000000007b61ec in gdb_do_one_event() () at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:347
 #13 0x00000000007b6224 in start_event_loop() () at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/event-loop.c:371
 #14 0x0000000000827f16 in captured_command_loop(void*) (data=0x0) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:325
 #15 0x00000000007b9c8e in catch_errors(int (*)(void*), void*, char*,
return_mask) (func=0x827ed4 <captured_command_loop(void*)>,
func_args=0x0, errstring=0x11df891 "", mask=RETURN_MASK_ALL) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/exceptions.c:236
 #16 0x000000000082928b 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.
 #17 0x00000000008292b4 in gdb_main(captured_main_args*)
(args=0x7fffffffd820) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/main.c:1158
 #18 0x0000000000412d4d in main(int, char**) (argc=4,
argv=0x7fffffffd928) at
/home/pedro/gdb/mygit/cxx-convertion/src/gdb/gdb.c:32

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.

With that out of the way, it looks to me that we can assume
that mi_ui_put (and thus mi_ui_out::put) is only ever meant to
be called with output _not_ redirected, and thus we can simplify
things a bit further, by eliminating the ui_file
write_buffer_on / rewind methods, keeping it contained in
the MI code.
Right, mi_ui_put is only used when printing/dumping responses to commands. For async events, the MI output is redirected to raw_stdout (through the event_channel, but still). So when printing an async event, a call to ui_out::field_int will write directly to raw_stdout, whereas when printing the response to a command, ui_out::field_int will write to mi_ui_out's internal string_file.
In the end, I like that you were able to remove rewind and write_buffer_on. My mind really couldn't get past the fact that you could call ->rewind() on an stdio_file. 

Thanks,

Simon
Index Nav: [Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav: [Date Prev] [Date Next] [Thread Prev] [Thread Next]