[PATCH 1/8] [gdb/testsuite] Set up dap log file in gdb.dap/type_checker.exp

[PATCH 1/8] [gdb/testsuite] Set up dap log file in gdb.dap/type_checker.exp

[Tom de Vries]

While debugging a slow-down in test-case gdb.dap/type_checker.exp due to a WIP
patch, I noticed that test-case gdb.dap/type_checker.exp doesn't have a dap
log file.

This is normally set up by dap_gdb_start, but the test-case doesn't use it.

Fix this by doing "set debug dap-log-file $logfile" in the test-case.

To make it easy to do so, I've factored out a new proc new_dap_log_file, and
while at likewise a new proc current_dap_log_file.

Note that the log file is currently empty.

Tested on x86_64-linux.
---
 gdb/testsuite/gdb.dap/type_check.exp |  3 +++
 gdb/testsuite/lib/dap-support.exp    | 22 +++++++++++++++-------
 2 files changed, 18 insertions(+), 7 deletions(-)

diff --git a/gdb/testsuite/gdb.dap/type_check.exp b/gdb/testsuite/gdb.dap/type_check.exp
index cda01299925..e6c9d73d871 100644
--- a/gdb/testsuite/gdb.dap/type_check.exp
+++ b/gdb/testsuite/gdb.dap/type_check.exp
@@ -26,6 +26,9 @@ set remote_python_file \
     [gdb_remote_download host ${srcdir}/${subdir}/${gdb_test_file_name}.py]
 gdb_test_no_output "source ${remote_python_file}" "load python file"
 
+set logfile [new_dap_log_file]
+gdb_test_no_output "set debug dap-log-file $logfile" "set dap log file"
+
 gdb_test_multiple "python check_everything()" "type checker" {
     -re -wrap "OK" {
 	pass $gdb_test_name
diff --git a/gdb/testsuite/lib/dap-support.exp b/gdb/testsuite/lib/dap-support.exp
index 979dfa2cd73..31f036eddf2 100644
--- a/gdb/testsuite/lib/dap-support.exp
+++ b/gdb/testsuite/lib/dap-support.exp
@@ -26,6 +26,19 @@ set dap_gdb_instance 0
 # is restarted.
 set dap_seq 1
 
+# Return the current DAP log file.
+proc current_dap_log_file {} {
+    global dap_gdb_instance
+    return [standard_output_file "dap.log.$dap_gdb_instance"]
+}
+
+# Return a new DAP log file.
+proc new_dap_log_file {} {
+    global dap_gdb_instance
+    incr dap_gdb_instance
+    return [current_dap_log_file]
+}
+
 # Start gdb using the DAP interpreter.
 proc dap_gdb_start {} {
     # Keep track of the number of times GDB has been launched.
@@ -34,13 +47,10 @@ proc dap_gdb_start {} {
 
     gdb_stdin_log_init
 
-    global dap_gdb_instance
-    incr dap_gdb_instance
-
     global GDBFLAGS stty_init
     save_vars { GDBFLAGS stty_init } {
 	set stty_init "-echo raw"
-	set logfile [standard_output_file "dap.log.$dap_gdb_instance"]
+	set logfile [new_dap_log_file]
 	append GDBFLAGS " -iex \"set debug dap-log-file $logfile\" -q -i=dap"
 	set res [gdb_spawn]
 	if {$res != 0} {
@@ -337,9 +347,7 @@ proc dap_target_remote {target} {
 
 # Read the most recent DAP log file and check it for exceptions.
 proc dap_check_log_file {} {
-    global dap_gdb_instance
-
-    set fd [open [standard_output_file "dap.log.$dap_gdb_instance"]]
+    set fd [open [current_dap_log_file]]
     set contents [read $fd]
     close $fd
 

base-commit: d1648ffe809ad288d989cd4f6794c01f524471f2
-- 
2.35.3

[PATCH 2/8] [gdb/dap] Factor out thread_log

[Tom de Vries]

In thread_wrapper I used a style where a message is prefixed with the thread
name.

Factor this out into a new function thread_log.

Also treat the GDB main thread special, because it's usual name is MainThread:
...
MainThread: <msg>
...
which is the default name assigned by python, so instead use the more
explicit:
...
GDB main: <msg>
...

Tested on aarch64-linux.
---
 gdb/python/lib/gdb/dap/startup.py | 13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index daaeb28e997..e68c5ba344e 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -64,7 +64,6 @@ def start_thread(name, target, args=()):
     correctly blocked."""
 
     def thread_wrapper(*args):
-        thread_name = threading.current_thread().name
         # Catch any exception, and log it.  If we let it escape here, it'll be
         # printed in gdb_stderr, which is not safe to access from anywhere but
         # gdb's main thread.
@@ -72,11 +71,11 @@ def start_thread(name, target, args=()):
             target(*args)
         except Exception as err:
             err_string = "%s, %s" % (err, type(err))
-            log(thread_name + ": caught exception: " + err_string)
+            thread_log("caught exception: " + err_string)
             log_stack()
         finally:
             # Log when a thread terminates.
-            log(thread_name + ": terminating")
+            thread_log("terminating")
 
     result = gdb.Thread(name=name, target=thread_wrapper, args=args, daemon=True)
     result.start()
@@ -174,6 +173,14 @@ def log(something, level=LogLevel.DEFAULT):
         dap_log.log_file.flush()
 
 
+def thread_log(something, level=LogLevel.DEFAULT):
+    if threading.current_thread() is _gdb_thread:
+        thread_name = "GDB main"
+    else:
+        thread_name = threading.current_thread().name
+    log(thread_name + ": " + something, level)
+
+
 def log_stack(level=LogLevel.DEFAULT):
     """Log a stack trace to the log file, if logging is enabled."""
     if dap_log.log_file is not None and level <= _log_level.value:
-- 
2.35.3

Re: [PATCH 2/8] [gdb/dap] Factor out thread_log

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

 
Tom> +def thread_log(something, level=LogLevel.DEFAULT):
Tom> +    if threading.current_thread() is _gdb_thread:

New exported functions should have a doc string.

Tom

Re: [PATCH 2/8] [gdb/dap] Factor out thread_log

[Tom de Vries]

On 2/20/24 16:30, Tom Tromey wrote:
>>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:
> 
>   
> Tom> +def thread_log(something, level=LogLevel.DEFAULT):
> Tom> +    if threading.current_thread() is _gdb_thread:
> 
> New exported functions should have a doc string.

Fixed in a v2 submission.

Thanks,
- Tom

> 
> Tom

[PATCH 3/8] [gdb/dap] Flush after printing in log_stack

[Tom de Vries]

I noticed that function log flushes the dap log file after printing, but
that function log_stack doesn't.

Fix this by also flushing the dap log file in log_stack.

Tested on aarch64-linux.
---
 gdb/python/lib/gdb/dap/startup.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index e68c5ba344e..edffc00902b 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -185,6 +185,7 @@ def log_stack(level=LogLevel.DEFAULT):
     """Log a stack trace to the log file, if logging is enabled."""
     if dap_log.log_file is not None and level <= _log_level.value:
         traceback.print_exc(file=dap_log.log_file)
+        dap_log.log_file.flush()
 
 
 @in_gdb_thread
-- 
2.35.3

Re: [PATCH 3/8] [gdb/dap] Flush after printing in log_stack

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> I noticed that function log flushes the dap log file after printing, but
Tom> that function log_stack doesn't.

Tom> Fix this by also flushing the dap log file in log_stack.

Tom> Tested on aarch64-linux.

Ok.
Approved-By: Tom Tromey <tom@tromey.com>

Tom

[PATCH 4/8] [gdb/dap] Make dap log printing thread-safe

[Tom de Vries]

I read that printing from different python threads is thread-unsafe, and I
noticed that the dap log printing is used from different threads, but doesn't
take care to make the printing thread-safe.

Fix this by using a lock to access LoggingParam.log_file.

Tested on aarch64-linux.
---
 gdb/python/lib/gdb/dap/startup.py | 31 ++++++++++++++++++-------------
 1 file changed, 18 insertions(+), 13 deletions(-)

diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index edffc00902b..fc86442db42 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -145,7 +145,9 @@ class LoggingParam(gdb.Parameter):
     set_doc = "Set the DAP logging status."
     show_doc = "Show the DAP logging status."
 
-    log_file = None
+    lock = threading.Lock()
+    with lock:
+        log_file = None
 
     def __init__(self):
         super().__init__(
@@ -154,12 +156,13 @@ class LoggingParam(gdb.Parameter):
         self.value = None
 
     def get_set_string(self):
-        # Close any existing log file, no matter what.
-        if self.log_file is not None:
-            self.log_file.close()
-            self.log_file = None
-        if self.value is not None:
-            self.log_file = open(self.value, "w")
+        with dap_log.lock:
+            # Close any existing log file, no matter what.
+            if self.log_file is not None:
+                self.log_file.close()
+                self.log_file = None
+            if self.value is not None:
+                self.log_file = open(self.value, "w")
         return ""
 
 
@@ -168,9 +171,10 @@ dap_log = LoggingParam()
 
 def log(something, level=LogLevel.DEFAULT):
     """Log SOMETHING to the log file, if logging is enabled."""
-    if dap_log.log_file is not None and level <= _log_level.value:
-        print(something, file=dap_log.log_file)
-        dap_log.log_file.flush()
+    with dap_log.lock:
+        if dap_log.log_file is not None and level <= _log_level.value:
+            print(something, file=dap_log.log_file)
+            dap_log.log_file.flush()
 
 
 def thread_log(something, level=LogLevel.DEFAULT):
@@ -183,9 +187,10 @@ def thread_log(something, level=LogLevel.DEFAULT):
 
 def log_stack(level=LogLevel.DEFAULT):
     """Log a stack trace to the log file, if logging is enabled."""
-    if dap_log.log_file is not None and level <= _log_level.value:
-        traceback.print_exc(file=dap_log.log_file)
-        dap_log.log_file.flush()
+    with dap_log.lock:
+        if dap_log.log_file is not None and level <= _log_level.value:
+            traceback.print_exc(file=dap_log.log_file)
+            dap_log.log_file.flush()
 
 
 @in_gdb_thread
-- 
2.35.3

Re: [PATCH 4/8] [gdb/dap] Make dap log printing thread-safe

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> I read that printing from different python threads is thread-unsafe, and I
Tom> noticed that the dap log printing is used from different threads, but doesn't
Tom> take care to make the printing thread-safe.

Tom> Fix this by using a lock to access LoggingParam.log_file.

Ok.
Approved-By: Tom Tromey <tom@tromey.com>


I wonder if we should just switch to the Python logging module.

Tom> -    log_file = None
Tom> +    lock = threading.Lock()
Tom> +    with lock:
Tom> +        log_file = None

I can't imagine locking is needed here.

Tom

Re: [PATCH 4/8] [gdb/dap] Make dap log printing thread-safe

[Tom de Vries]

On 2/20/24 16:32, Tom Tromey wrote:
>>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:
> 
> Tom> I read that printing from different python threads is thread-unsafe, and I
> Tom> noticed that the dap log printing is used from different threads, but doesn't
> Tom> take care to make the printing thread-safe.
> 
> Tom> Fix this by using a lock to access LoggingParam.log_file.
> 
> Ok.
> Approved-By: Tom Tromey <tom@tromey.com>
> 
> 
> I wonder if we should just switch to the Python logging module.
> 
> Tom> -    log_file = None
> Tom> +    lock = threading.Lock()
> Tom> +    with lock:
> Tom> +        log_file = None
> 
> I can't imagine locking is needed here.

Dropped that bit, and committed.

Thanks,
- Tom

[PATCH 5/8] [gdb/dap] Fix race between dap startup and dap log file

[Tom de Vries]

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:
- initially logging to a string instead, and
- dumping the string to the log file once the log file is initialized.

This has the drawback that the string can keep growing indefinitely if a log
file is never set, this will be addressed in a following commit.

Tested on aarch64-linux.

PR dap/31386
Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31386
---
 gdb/python/lib/gdb/dap/startup.py | 17 ++++++++++++++---
 gdb/testsuite/gdb.dap/eof.exp     |  3 +++
 gdb/testsuite/lib/dap-support.exp | 10 ++++++++++
 3 files changed, 27 insertions(+), 3 deletions(-)

diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index fc86442db42..596012688ac 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -21,6 +21,7 @@ import queue
 import threading
 import traceback
 import sys
+import io
 
 from enum import IntEnum, auto
 
@@ -147,7 +148,7 @@ class LoggingParam(gdb.Parameter):
 
     lock = threading.Lock()
     with lock:
-        log_file = None
+        log_file = io.StringIO()
 
     def __init__(self):
         super().__init__(
@@ -157,12 +158,20 @@ class LoggingParam(gdb.Parameter):
 
     def get_set_string(self):
         with dap_log.lock:
+            initial_log = None
+            if isinstance(self.log_file, io.StringIO):
+                initial_log = self.log_file.getvalue()
+                self.log_file.close()
+                self.log_file = None
             # Close any existing log file, no matter what.
             if self.log_file is not None:
                 self.log_file.close()
                 self.log_file = None
             if self.value is not None:
                 self.log_file = open(self.value, "w")
+                if initial_log != None:
+                    print(initial_log, file=self.log_file)
+                    self.log_file.flush()
         return ""
 
 
@@ -174,7 +183,8 @@ def log(something, level=LogLevel.DEFAULT):
     with dap_log.lock:
         if dap_log.log_file is not None and level <= _log_level.value:
             print(something, file=dap_log.log_file)
-            dap_log.log_file.flush()
+            if not isinstance(dap_log.log_file, io.StringIO):
+                dap_log.log_file.flush()
 
 
 def thread_log(something, level=LogLevel.DEFAULT):
@@ -190,7 +200,8 @@ def log_stack(level=LogLevel.DEFAULT):
     with dap_log.lock:
         if dap_log.log_file is not None and level <= _log_level.value:
             traceback.print_exc(file=dap_log.log_file)
-            dap_log.log_file.flush()
+            if not isinstance(dap_log.log_file, io.StringIO):
+                dap_log.log_file.flush()
 
 
 @in_gdb_thread
diff --git a/gdb/testsuite/gdb.dap/eof.exp b/gdb/testsuite/gdb.dap/eof.exp
index 9c17725c0d0..404a069246f 100644
--- a/gdb/testsuite/gdb.dap/eof.exp
+++ b/gdb/testsuite/gdb.dap/eof.exp
@@ -35,3 +35,6 @@ catch "wait -i $gdb_spawn_id"
 unset gdb_spawn_id
 
 dap_check_log_file
+
+# Check that first log message is present.
+dap_check_log_file_re [string_to_regexp "+++ set python print-stack full"]
diff --git a/gdb/testsuite/lib/dap-support.exp b/gdb/testsuite/lib/dap-support.exp
index 31f036eddf2..5818d815df3 100644
--- a/gdb/testsuite/lib/dap-support.exp
+++ b/gdb/testsuite/lib/dap-support.exp
@@ -366,6 +366,16 @@ proc dap_check_log_file {} {
     }
 }
 
+# Read the most recent DAP log file and check that regexp RE matches.
+proc dap_check_log_file_re { re } {
+    set fd [open [current_dap_log_file]]
+    set contents [read $fd]
+    close $fd
+
+    set ok [regexp $re $contents]
+    gdb_assert {$ok} "log file matched $re"
+}
+
 # Cleanly shut down gdb.  TERMINATE is passed as the terminateDebuggee
 # parameter to the request.
 proc dap_shutdown {{terminate false}} {
-- 
2.35.3

Re: [PATCH 5/8] [gdb/dap] Fix race between dap startup and dap log file

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> Fix this by:
Tom> - initially logging to a string instead, and
Tom> - dumping the string to the log file once the log file is initialized.

Tom> This has the drawback that the string can keep growing indefinitely if a log
Tom> file is never set, this will be addressed in a following commit.

I don't like this approach.  There's almost never any need to log
anything, so I think this is adding complexity to something where,
really, we don't care.  IMO most of the early logging isn't even useful.
In the bug you pointed out how dap.run logs some commands early
on... but even this is just because it is convenient to call
exec_and_log, not because these logs are useful.

Tom

[PATCH 6/8] [gdb/dap] Don't let dap log string grow indefinitely

[Tom de Vries]

As mentioned in commit "[gdb/dap] Fix race between dap startup and dap log
file", initially logging to a string has the drawback that the string can keep
growing indefinitely if a log file is never set.

Fix this by:
- using the pre_command_loop interpreter hook to detect this situation, and
- stopping the logging to string.

Tested on aarch64-linux.

PR dap/31386
Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31386
---
 gdb/python/lib/gdb/dap/__init__.py | 14 ++++++++++++++
 gdb/python/lib/gdb/dap/startup.py  |  5 +++++
 gdb/python/py-dap.c                | 21 +++++++++++++++++++++
 3 files changed, 40 insertions(+)

diff --git a/gdb/python/lib/gdb/dap/__init__.py b/gdb/python/lib/gdb/dap/__init__.py
index f60b3fda1db..92ea2afeaa5 100644
--- a/gdb/python/lib/gdb/dap/__init__.py
+++ b/gdb/python/lib/gdb/dap/__init__.py
@@ -71,3 +71,17 @@ def run():
     # Note the inferior output is opened in text mode.
     server = Server(open(saved_in, "rb"), open(saved_out, "wb"), open(rfd, "r"))
     startup.start_dap(server.main_loop)
+
+
+# Whether the interactive session has started.
+session_started = False
+
+
+def pre_command_loop():
+    global session_started
+    if not session_started:
+        # The pre_command_loop interpreter hook can be called several times.
+        # The first time it's called, it means we're starting an interactive
+        # session.
+        session_started = True
+        startup.dap_log.session_started()
diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index 596012688ac..3b8df2fbf32 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -174,6 +174,11 @@ class LoggingParam(gdb.Parameter):
                     self.log_file.flush()
         return ""
 
+    def session_started(self):
+        with dap_log.lock:
+            if isinstance(self.log_file, io.StringIO):
+                self.log_file = None
+
 
 dap_log = LoggingParam()
 
diff --git a/gdb/python/py-dap.c b/gdb/python/py-dap.c
index 5757c150165..2b889e3b573 100644
--- a/gdb/python/py-dap.c
+++ b/gdb/python/py-dap.c
@@ -61,6 +61,8 @@ class dap_interp final : public interp
     return m_ui_out.get ();
   }
 
+  void pre_command_loop () override;
+
 private:
 
   std::unique_ptr<ui_out> m_ui_out;
@@ -87,6 +89,25 @@ dap_interp::init (bool top_level)
   current_ui->m_input_interactive_p = false;
 }
 
+void
+dap_interp::pre_command_loop ()
+{
+  gdbpy_enter enter_py;
+
+  gdbpy_ref<> dap_module (PyImport_ImportModule ("gdb.dap"));
+  if (dap_module == nullptr)
+    gdbpy_handle_exception ();
+
+  gdbpy_ref<> func (PyObject_GetAttrString (dap_module.get (),
+					    "pre_command_loop"));
+  if (func == nullptr)
+    gdbpy_handle_exception ();
+
+  gdbpy_ref<> result_obj (PyObject_CallObject (func.get (), nullptr));
+  if (result_obj == nullptr)
+    gdbpy_handle_exception ();
+}
+
 void _initialize_py_interp ();
 void
 _initialize_py_interp ()
-- 
2.35.3

Re: [PATCH 6/8] [gdb/dap] Don't let dap log string grow indefinitely

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> As mentioned in commit "[gdb/dap] Fix race between dap startup and dap log
Tom> file", initially logging to a string has the drawback that the string can keep
Tom> growing indefinitely if a log file is never set.

Tom> Fix this by:
Tom> - using the pre_command_loop interpreter hook to detect this situation, and
Tom> - stopping the logging to string.

Adding a pre_command_loop hook like this seems fine.
If you really want to solve the early logging problem, what I'd suggest
is using this patch and then splitting 'run' into two parts, with the
second part doing all the actual work.

 
Tom> +void
Tom> +dap_interp::pre_command_loop ()
Tom> +{
Tom> +  gdbpy_enter enter_py;
Tom> +
Tom> +  gdbpy_ref<> dap_module (PyImport_ImportModule ("gdb.dap"));
Tom> +  if (dap_module == nullptr)
Tom> +    gdbpy_handle_exception ();
Tom> +
Tom> +  gdbpy_ref<> func (PyObject_GetAttrString (dap_module.get (),
Tom> +					    "pre_command_loop"));
Tom> +  if (func == nullptr)
Tom> +    gdbpy_handle_exception ();
Tom> +
Tom> +  gdbpy_ref<> result_obj (PyObject_CallObject (func.get (), nullptr));
Tom> +  if (result_obj == nullptr)
Tom> +    gdbpy_handle_exception ();

IMO the bulk of this should be refactored into a helper function now.
It's nearly identical to dap_interp::init.

Tom

Re: [PATCH 6/8] [gdb/dap] Don't let dap log string grow indefinitely

[Tom de Vries]

On 2/20/24 16:41, Tom Tromey wrote:
>>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:
> 
> Tom> As mentioned in commit "[gdb/dap] Fix race between dap startup and dap log
> Tom> file", initially logging to a string has the drawback that the string can keep
> Tom> growing indefinitely if a log file is never set.
> 
> Tom> Fix this by:
> Tom> - using the pre_command_loop interpreter hook to detect this situation, and
> Tom> - stopping the logging to string.
> 
> Adding a pre_command_loop hook like this seems fine.
> If you really want to solve the early logging problem, what I'd suggest
> is using this patch and then splitting 'run' into two parts, with the
> second part doing all the actual work.
> 

Done in a v2.  I did the split between thread setup and thread start, 
though I'm not sure that's where you want it.
>   
> Tom> +void
> Tom> +dap_interp::pre_command_loop ()
> Tom> +{
> Tom> +  gdbpy_enter enter_py;
> Tom> +
> Tom> +  gdbpy_ref<> dap_module (PyImport_ImportModule ("gdb.dap"));
> Tom> +  if (dap_module == nullptr)
> Tom> +    gdbpy_handle_exception ();
> Tom> +
> Tom> +  gdbpy_ref<> func (PyObject_GetAttrString (dap_module.get (),
> Tom> +					    "pre_command_loop"));
> Tom> +  if (func == nullptr)
> Tom> +    gdbpy_handle_exception ();
> Tom> +
> Tom> +  gdbpy_ref<> result_obj (PyObject_CallObject (func.get (), nullptr));
> Tom> +  if (result_obj == nullptr)
> Tom> +    gdbpy_handle_exception ();
> 
> IMO the bulk of this should be refactored into a helper function now.
> It's nearly identical to dap_interp::init.

Done in a v2.

Thanks,
- Tom

[PATCH 7/8] [gdb/dap] Join JSON reader and writer threads with DAP thread

[Tom de Vries]

The DAP interpreter runs in its own thread, and starts a few threads:
- the JSON reader thread,
- the JSON writer thread, and
- the inferior output reader thread.

As part of the DAP shutdown, both the JSON reader thread and the JSON writer
thread, as well as the DAP main thread run to exit, but these exits are not
ordered in any way.

Wait in the main DAP thread for the exit of the JSON writer thread.

This makes sure that the responses are flushed to the DAP client before DAP
shutdown.

An earlier version of this patch used Queue.task_done() to accomplish the
same, but that didn't guarantee writing the "<thread name>: terminating"
log entry from thread_wrapper before DAP shutdown.

While we're at it, do the same for the JSON reader thread.

Tested on aarch64-linux.

PR dap/31380
Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31380
---
 gdb/python/lib/gdb/dap/io.py      | 2 +-
 gdb/python/lib/gdb/dap/server.py  | 6 ++++--
 gdb/python/lib/gdb/dap/startup.py | 1 +
 3 files changed, 6 insertions(+), 3 deletions(-)

diff --git a/gdb/python/lib/gdb/dap/io.py b/gdb/python/lib/gdb/dap/io.py
index 4edd504c727..81e835c7527 100644
--- a/gdb/python/lib/gdb/dap/io.py
+++ b/gdb/python/lib/gdb/dap/io.py
@@ -79,4 +79,4 @@ def start_json_writer(stream, queue):
             stream.write(body_bytes)
             stream.flush()
 
-    start_thread("JSON writer", _json_writer)
+    return start_thread("JSON writer", _json_writer)
diff --git a/gdb/python/lib/gdb/dap/server.py b/gdb/python/lib/gdb/dap/server.py
index 7cc5a4681ee..f547fcc76bc 100644
--- a/gdb/python/lib/gdb/dap/server.py
+++ b/gdb/python/lib/gdb/dap/server.py
@@ -212,8 +212,8 @@ class Server:
         # Before looping, start the thread that writes JSON to the
         # client, and the thread that reads output from the inferior.
         start_thread("output reader", self._read_inferior_output)
-        start_json_writer(self.out_stream, self.write_queue)
-        start_thread("JSON reader", self._reader_thread)
+        json_writer = start_json_writer(self.out_stream, self.write_queue)
+        json_reader = start_thread("JSON reader", self._reader_thread)
         while not self.done:
             cmd = self.read_queue.get()
             # A None value here means the reader hit EOF.
@@ -229,6 +229,8 @@ class Server:
         # JSON-writing thread, so that we can ensure that all
         # responses are flushed to the client before exiting.
         self.write_queue.put(None)
+        json_writer.join()
+        json_reader.join()
 
     @in_dap_thread
     def send_event_later(self, event, body=None):
diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index 3b8df2fbf32..8dd89df2614 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -80,6 +80,7 @@ def start_thread(name, target, args=()):
 
     result = gdb.Thread(name=name, target=thread_wrapper, args=args, daemon=True)
     result.start()
+    return result
 
 
 def start_dap(target):
-- 
2.35.3

Re: [PATCH 7/8] [gdb/dap] Join JSON reader and writer threads with DAP thread

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> The DAP interpreter runs in its own thread, and starts a few threads:
Tom> - the JSON reader thread,
Tom> - the JSON writer thread, and
Tom> - the inferior output reader thread.

I didn't realize you can join a daemonic Python thread.
In other thread systems you can't join such threads.

Anyway this is ok.  Thanks.
Approved-By: Tom Tromey <tom@tromey.com>

Tom

Re: [PATCH 7/8] [gdb/dap] Join JSON reader and writer threads with DAP thread

[Tom Tromey]

Tom> While we're at it, do the same for the JSON reader thread.

I've been thinking about this and I am no longer sure it's ok to wait
for the reader thread.

I don't think DAP requires that the client shut down the pipe on exit.
It only requires sending the request.

So I tend to think gdb ought to exit when requested and not wait for the
reader thread.

Tom

Re: [PATCH 7/8] [gdb/dap] Join JSON reader and writer threads with DAP thread

[Tom de Vries]

On 2/20/24 21:01, Tom Tromey wrote:
> Tom> While we're at it, do the same for the JSON reader thread.
> 
> I've been thinking about this and I am no longer sure it's ok to wait
> for the reader thread.
> 
> I don't think DAP requires that the client shut down the pipe on exit.
> It only requires sending the request.
> 
> So I tend to think gdb ought to exit when requested and not wait for the
> reader thread.

Committed with that bit dropped.

Thanks,
- Tom

[PATCH 8/8] [gdb/dap] Fix race between dap exit and gdb exit

[Tom de Vries]

When DAP shuts down due to an EOF event, there's a race between:
- gdb's main thread handling a SIGHUP, and
- the DAP main thread exiting.

Fix this by waiting for DAP's main thread exit during the gdb_exiting event.

[ Note that the variable _dap_thread is set in the DAP main thread, but
possibly accessed from other threads in ensure_dap_thread:
...
        assert threading.current_thread() is _dap_thread
...
In principle access should be guarded with a lock, but I suppose seeing the
old None value also gives the desired outcome of the comparison, so this looks
harmless. ]

Since this means accessing _dap_thread in gdb's main thread, we have to make
sure it's available there as well.  Do this by introducing a variable
_dap_thread_for_gdb_thread, to avoid needing locking access to _dap_thread.

Tested on aarch64-linux.

PR dap/31380
Bug: https://sourceware.org/bugzilla/show_bug.cgi?id=31380
---
 gdb/python/lib/gdb/dap/events.py  |  8 +++++++-
 gdb/python/lib/gdb/dap/startup.py | 21 +++++++++++++++++++--
 gdb/testsuite/gdb.dap/eof.exp     | 10 ++++++++++
 3 files changed, 36 insertions(+), 3 deletions(-)

diff --git a/gdb/python/lib/gdb/dap/events.py b/gdb/python/lib/gdb/dap/events.py
index 41302229ee5..d9e3a6f8d3f 100644
--- a/gdb/python/lib/gdb/dap/events.py
+++ b/gdb/python/lib/gdb/dap/events.py
@@ -16,7 +16,7 @@
 import gdb
 
 from .server import send_event
-from .startup import exec_and_log, in_gdb_thread, log
+from .startup import exec_and_log, in_gdb_thread, log, dap_thread_join
 from .modules import is_module, make_module
 
 
@@ -275,6 +275,11 @@ def _on_inferior_call(event):
             send_event("stopped", obj)
 
 
+@in_gdb_thread
+def _on_gdb_exiting(event):
+    dap_thread_join()
+
+
 gdb.events.stop.connect(_on_stop)
 gdb.events.exited.connect(_on_exit)
 gdb.events.new_thread.connect(_new_thread)
@@ -283,3 +288,4 @@ gdb.events.cont.connect(_cont)
 gdb.events.new_objfile.connect(_new_objfile)
 gdb.events.free_objfile.connect(_objfile_removed)
 gdb.events.inferior_call.connect(_on_inferior_call)
+gdb.events.gdb_exiting.connect(_on_gdb_exiting)
diff --git a/gdb/python/lib/gdb/dap/startup.py b/gdb/python/lib/gdb/dap/startup.py
index 8dd89df2614..2c34ddac820 100644
--- a/gdb/python/lib/gdb/dap/startup.py
+++ b/gdb/python/lib/gdb/dap/startup.py
@@ -37,10 +37,15 @@ else:
 _gdb_thread = threading.current_thread()
 
 
-# The DAP thread.
+# The DAP thread, stored in the DAP thread.
 _dap_thread = None
 
 
+# The DAP thread, stored in the GDB main thread.  This to avoid using one
+# variable and having to use a lock to access it.
+_dap_thread_for_gdb_thread = None
+
+
 # "Known" exceptions are wrapped in a DAP exception, so that, by
 # default, only rogue exceptions are logged -- this is then used by
 # the test suite.
@@ -94,7 +99,9 @@ def start_dap(target):
         _dap_thread = threading.current_thread()
         target()
 
-    start_thread("DAP", really_start_dap)
+    # Note that we set _dap_thread in both the DAP and the GDB main thread.
+    global _dap_thread_for_gdb_thread
+    _dap_thread_for_gdb_thread = start_thread("DAP", really_start_dap)
 
 
 def in_gdb_thread(func):
@@ -223,6 +230,16 @@ def exec_and_log(cmd):
         log_stack()
 
 
+def dap_thread_join():
+    global _dap_thread_for_gdb_thread
+    if _dap_thread_for_gdb_thread != None:
+        thread_log("joining dap thread ...")
+        _dap_thread_for_gdb_thread.join()
+        thread_log("joining dap thread done")
+    else:
+        thread_log("no dap thread to join")
+
+
 class Invoker(object):
     """A simple class that can invoke a gdb command."""
 
diff --git a/gdb/testsuite/gdb.dap/eof.exp b/gdb/testsuite/gdb.dap/eof.exp
index 404a069246f..27661f793b7 100644
--- a/gdb/testsuite/gdb.dap/eof.exp
+++ b/gdb/testsuite/gdb.dap/eof.exp
@@ -38,3 +38,13 @@ dap_check_log_file
 
 # Check that first log message is present.
 dap_check_log_file_re [string_to_regexp "+++ set python print-stack full"]
+
+# There should be one "READ:" for the initialize request, and at least one
+# "WROTE:" for the initialize response.
+dap_check_log_file_re "READ:"
+dap_check_log_file_re "WROTE:"
+
+# Check that all thread termination messages are there.
+dap_check_log_file_re "JSON writer: terminating"
+dap_check_log_file_re "JSON reader: terminating"
+dap_check_log_file_re "DAP: terminating"
-- 
2.35.3

Re: [PATCH 8/8] [gdb/dap] Fix race between dap exit and gdb exit

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> +@in_gdb_thread
Tom> +def _on_gdb_exiting(event):
Tom> +    dap_thread_join()

I think it's better not to export dap_thread_join and then import it
here, but instead just add to the event listener exactly where it's
needed.

Tom> +    global _dap_thread_for_gdb_thread
Tom> +    _dap_thread_for_gdb_thread = start_thread("DAP", really_start_dap)
 
You don't even need a new global if you add the listener here.

Tom> +def dap_thread_join():
Tom> +    global _dap_thread_for_gdb_thread
Tom> +    if _dap_thread_for_gdb_thread != None:

None of this will be necessary with the above, but FYI in Python it's
idiomatic to do this comparison with "if blah is not None"

Tom

Re: [PATCH 8/8] [gdb/dap] Fix race between dap exit and gdb exit

[Tom de Vries]

On 2/20/24 16:51, Tom Tromey wrote:
>>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:
> 
> Tom> +@in_gdb_thread
> Tom> +def _on_gdb_exiting(event):
> Tom> +    dap_thread_join()
> 
> I think it's better not to export dap_thread_join and then import it
> here, but instead just add to the event listener exactly where it's
> needed.
> 

Done in a v2.

> Tom> +    global _dap_thread_for_gdb_thread
> Tom> +    _dap_thread_for_gdb_thread = start_thread("DAP", really_start_dap)
>   
> You don't even need a new global if you add the listener here.
> 

OK, reverted back to using _dap_thread in a v2.

> Tom> +def dap_thread_join():
> Tom> +    global _dap_thread_for_gdb_thread
> Tom> +    if _dap_thread_for_gdb_thread != None:
> 
> None of this will be necessary with the above, but FYI in Python it's
> idiomatic to do this comparison with "if blah is not None"

When running test-case gdb.dap/type_check.exp, the dap module is 
imported, but no server is started and consequently there's no dap 
thread.  If we don't test for none here, we get a python exception 
telling us that None doesn't support join.

In the v2, I've rewritten this into an early exit with a comment to make 
it more clear.

Thanks,
- Tom

Re: [PATCH 1/8] [gdb/testsuite] Set up dap log file in gdb.dap/type_checker.exp

[Tom Tromey]

>>>>> "Tom" == Tom de Vries <tdevries@suse.de> writes:

Tom> While debugging a slow-down in test-case gdb.dap/type_checker.exp due to a WIP
Tom> patch, I noticed that test-case gdb.dap/type_checker.exp doesn't have a dap
Tom> log file.

Tom> This is normally set up by dap_gdb_start, but the test-case doesn't use it.

Tom> Fix this by doing "set debug dap-log-file $logfile" in the test-case.

Tom> To make it easy to do so, I've factored out a new proc new_dap_log_file, and
Tom> while at likewise a new proc current_dap_log_file.

Tom> Note that the log file is currently empty.

Ok.
Approved-By: Tom Tromey <tom@tromey.com>

Tom