In dap-support.exp, dap_gdb_start we do: ... append GDBFLAGS " -iex \"set debug dap-log-file $logfile\" -q -i=dap" ... While the dap log file setting comes before the dap interpreter setting, that's not the order in which things happen. Consequently, there's a race between dap interpreter startup and dap log file initialization. The logging procs are setup to just do nothing if the log file is not yet initialized. I found this by adding this to gdb.dap/eof.exp (dap_check_log_file_re not yet in trunk): ... diff --git a/gdb/testsuite/gdb.dap/eof.exp b/gdb/testsuite/gdb.dap/eof.exp index 9c17725c0d0..a64ac227880 100644 --- a/gdb/testsuite/gdb.dap/eof.exp +++ b/gdb/testsuite/gdb.dap/eof.exp @@ -35,3 +35,8 @@ catch "wait -i $gdb_spawn_id" unset gdb_spawn_id dap_check_log_file +dap_check_log_file_re "JSON writer: terminating" +dap_check_log_file_re "JSON reader: terminating" +dap_check_log_file_re "DAP: terminating" +dap_check_log_file_re "WROTE:" +dap_check_log_file_re "READ:" ... and the last check fails regularly, because the initial request: ... READ: <<<{"seq": 1, "type": "request", "command": "initialize", "arguments": {"clientID": "gdb testsuite", "supportsVariableType": true, "supportsVariablePaging": true, "supportsMemoryReferences": true}}>>> ... is often not logged. I also tried using -eiex but that happens before interpreter setup, which means the "set debug dap-log-file" command hasn't been setup yet, so there's no log file at all. I wondered whether to classify with component testsuite, but I think it should be dap because it's a bug if we can't log a complete dap session.
One way to address this is to keep the log in a string until a file is set.
(In reply to Tom de Vries from comment #1) > One way to address this is to keep the log in a string until a file is set. That may never happen, so we'd end up accumulating a large string. There should probably be some way for the DAP interpreter to not start accepting requests until all the command-line options have been handled. Maybe a new interpreter method is needed.
(In reply to Tom Tromey from comment #2) > (In reply to Tom de Vries from comment #1) > > One way to address this is to keep the log in a string until a file is set. > I have a patch for this. > That may never happen, so we'd end up accumulating a large string. > > There should probably be some way for the DAP interpreter to not > start accepting requests until all the command-line options have > been handled. Maybe a new interpreter method is needed. I've written a patch adding a gdb_starting_session observer/event (based on gdb_exiting), which can be used for this. However, when trying to use this into dap I noticed that the first log is done by dap setup in the gdb main thread, so that's too early to fix in this way. The way to fix this is start log output in a string. At the gdb_starting_session event, we either: - have switched over to a log file, in which case the string is already printed, or, - have not switched over to a log file, in which case we discard the string and stop collecting the output in a string. So, I'll combine the two patches to fix this.
FYI, I have a fix as part of this ( https://github.com/vries/gdb/pull/new/dap/exiting-race-4 ) branch. To be submitted once cleaned up.
I don't think you need a new event, just a new interpreter method; and then split the DAP initialization in two. Very early logging (before the "true" startup) probably isn't interesting anyway.
Fix submitted as part of this ( https://sourceware.org/pipermail/gdb-patches/2024-February/206652.html ) series.
(In reply to Tom Tromey from comment #5) > I don't think you need a new event, just a new interpreter > method; and then split the DAP initialization in two. I managed to use the existing interpreter method pre_command_loop. > Very early logging (before the "true" startup) probably > isn't interesting anyway. Not sure what the true start is, but AFAICT the first thing DAP does is log a message with the command it's about to run: ... def run(): """Main entry point for the DAP server. This is called by the GDB DAP interpreter.""" startup.exec_and_log("set python print-stack full") ...
The master branch has been updated by Tom de Vries <vries@sourceware.org>: https://sourceware.org/git/gitweb.cgi?p=binutils-gdb.git;h=05bf17f03b890424312163463754de63cee73074 commit 05bf17f03b890424312163463754de63cee73074 Author: Tom de Vries <tdevries@suse.de> Date: Thu Feb 22 11:35:26 2024 +0100 [gdb/dap] Fix race between dap startup and dap log file In dap_gdb_start we do: ... append GDBFLAGS " -iex \"set debug dap-log-file $logfile\" -q -i=dap" ... While the dap log file setting comes before the dap interpreter setting, the order is the other way around: - first, the dap interpreter is started - second, the -iex commands are executed and the log file is initialized. Consequently, there's a race between dap interpreter startup and dap log file initialization. This cannot be fixed by using -eiex instead. Before the interpreter is started, the "set debug dap-log-file" command is not yet registered. Fix this by postponing the start of the DAP server until GDB has processed all command files. Tested on aarch64-linux. Approved-By: Tom Tromey <tom@tromey.com> PR dap/31386 Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31386
Fixed.