ilya-nozhkin created this revision.
ilya-nozhkin added reviewers: jingham, clayborg.
ilya-nozhkin requested review of this revision.
Herald added a project: LLDB.
Herald added a subscriber: lldb-commits.

The race is between these two pieces of code that are executed in two separate
lldb-vscode threads (the first is in the main thread and another is in the
event-handling thread):

  // lldb-vscode.cpp
  g_vsc.debugger.SetAsync(false);
  g_vsc.target.Launch(launch_info, error);
  g_vsc.debugger.SetAsync(true);



  // Target.cpp
  bool old_async = debugger.GetAsyncExecution();
  debugger.SetAsyncExecution(true);
  debugger.GetCommandInterpreter().HandleCommands(GetCommands(), exc_ctx,
                                                  options, result);
  debugger.SetAsyncExecution(old_async);

The sequence that leads to the bug is this one:

1. Main thread enables synchronous mode and launches the process.
2. When the process is launched, it generates the first stop event.
3. This stop event is catched by the event-handling thread and DoOnRemoval is 
invoked.
4. Inside DoOnRemoval, this thread runs stop hooks. And before running stop 
hooks, the current synchronization mode is stored into old_async (and right now 
it is equal to "false").
5. The main thread finishes the launch and returns to lldb-vscode, the 
synchronization mode is restored to asynchronous by lldb-vscode.
6. Event-handling thread finishes stop hooks processing and restores the 
synchronization mode according to old_async (i.e. makes the mode synchronous)
7. And now the mode is synchronous while lldb-vscode expects it to be 
asynchronous. Synchronous mode forbids the process to broadcast public stop 
events, so, VS Code just hangs because lldb-vscode doesn't notify it about 
stops.

So, this diff introduces a lock of synchronization mode for cases when it should
be saved before some action and then restored.

The bug is only present on Windows but it seems to be just a coincidence. On
Linux, as I understand, the first stop event is intercepted by hijacking
listener and is never popped out of the queue, so, stop hooks are not executed
and the race doesn't happen.

So, this diff also fixes some problems with lldb-vscode tests on Windows to make
it possible to run the related test. Other tests still can't be enabled because
the debugged program prints something into stdout and LLDB can't intercept this
output and redirect it to lldb-vscode properly.


Repository:
  rG LLVM Github Monorepo

https://reviews.llvm.org/D119548

Files:
  lldb/include/lldb/Core/Debugger.h
  lldb/include/lldb/Interpreter/CommandInterpreter.h
  lldb/packages/Python/lldbsuite/test/lldbtest.py
  lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py
  lldb/source/Core/Debugger.cpp
  lldb/source/Interpreter/CommandInterpreter.cpp
  lldb/source/Target/Target.cpp
  lldb/test/API/tools/lldb-vscode/stop-hooks/Makefile
  lldb/test/API/tools/lldb-vscode/stop-hooks/TestVSCode_stop_hooks.py
  lldb/test/API/tools/lldb-vscode/stop-hooks/main.c

Index: lldb/test/API/tools/lldb-vscode/stop-hooks/main.c
===================================================================
--- /dev/null
+++ lldb/test/API/tools/lldb-vscode/stop-hooks/main.c
@@ -0,0 +1 @@
+int main() { return 0; }
Index: lldb/test/API/tools/lldb-vscode/stop-hooks/TestVSCode_stop_hooks.py
===================================================================
--- /dev/null
+++ lldb/test/API/tools/lldb-vscode/stop-hooks/TestVSCode_stop_hooks.py
@@ -0,0 +1,35 @@
+"""
+Test stop hooks
+"""
+
+
+from lldbsuite.test.decorators import *
+from lldbsuite.test.lldbtest import *
+import lldbvscode_testcase
+
+
+class TestVSCode_stop_hooks(lldbvscode_testcase.VSCodeTestCaseBase):
+
+    mydir = TestBase.compute_mydir(__file__)
+
+    @skipIfRemote
+    def test_stop_hooks_before_run(self):
+        '''
+            Test that there is no race condition between lldb-vscode and
+            stop hooks executor
+        '''
+        program = self.getBuildArtifact("a.out")
+        preRunCommands = ['target stop-hook add -o help']
+        self.build_and_launch(program, stopOnEntry=True, preRunCommands=preRunCommands)
+
+        # The first stop is on entry.
+        self.continue_to_next_stop()
+
+        breakpoint_ids = self.set_function_breakpoints(['main'])
+        # This request hangs if the race happens, because, in that case, the
+        # command interpreter is in synchronous mode while lldb-vscode expects
+        # it to be in asynchronous mode, so, the process doesn't send the stop
+        # event to "lldb.Debugger" listener (which is monitored by lldb-vscode).
+        self.continue_to_breakpoints(breakpoint_ids)
+
+        self.continue_to_exit()
Index: lldb/test/API/tools/lldb-vscode/stop-hooks/Makefile
===================================================================
--- /dev/null
+++ lldb/test/API/tools/lldb-vscode/stop-hooks/Makefile
@@ -0,0 +1,3 @@
+C_SOURCES := main.c
+
+include Makefile.rules
Index: lldb/source/Target/Target.cpp
===================================================================
--- lldb/source/Target/Target.cpp
+++ lldb/source/Target/Target.cpp
@@ -3457,11 +3457,12 @@
   options.SetAddToHistory(false);
 
   // Force Async:
-  bool old_async = debugger.GetAsyncExecution();
-  debugger.SetAsyncExecution(true);
-  debugger.GetCommandInterpreter().HandleCommands(GetCommands(), exc_ctx,
-                                                  options, result);
-  debugger.SetAsyncExecution(old_async);
+  debugger.DoWithLockedAsynchronization(
+      true,
+      [&debugger, &commands = GetCommands(), &exc_ctx, &options, &result]() {
+        debugger.GetCommandInterpreter().HandleCommands(commands, exc_ctx,
+                                                        options, result);
+      });
   lldb::ReturnStatus status = result.GetStatus();
   if (status == eReturnStatusSuccessContinuingNoResult ||
       status == eReturnStatusSuccessContinuingResult)
Index: lldb/source/Interpreter/CommandInterpreter.cpp
===================================================================
--- lldb/source/Interpreter/CommandInterpreter.cpp
+++ lldb/source/Interpreter/CommandInterpreter.cpp
@@ -2447,124 +2447,120 @@
   RestoreExecutionContext();
 }
 
-void CommandInterpreter::HandleCommands(const StringList &commands,
-                                        const CommandInterpreterRunOptions &options,
-                                        CommandReturnObject &result) {
+void CommandInterpreter::HandleCommands(
+    const StringList &commands, const CommandInterpreterRunOptions &options,
+    CommandReturnObject &result) {
   size_t num_lines = commands.GetSize();
 
-  // If we are going to continue past a "continue" then we need to run the
-  // commands synchronously. Make sure you reset this value anywhere you return
-  // from the function.
-
-  bool old_async_execution = m_debugger.GetAsyncExecution();
-
-  if (!options.GetStopOnContinue()) {
-    m_debugger.SetAsyncExecution(false);
-  }
-
-  for (size_t idx = 0; idx < num_lines && !WasInterrupted(); idx++) {
-    const char *cmd = commands.GetStringAtIndex(idx);
-    if (cmd[0] == '\0')
-      continue;
-
-    if (options.GetEchoCommands()) {
-      // TODO: Add Stream support.
-      result.AppendMessageWithFormat("%s %s\n",
-                                     m_debugger.GetPrompt().str().c_str(), cmd);
-    }
-
-    CommandReturnObject tmp_result(m_debugger.GetUseColor());
-    tmp_result.SetInteractive(result.GetInteractive());
-    tmp_result.SetSuppressImmediateOutput(true);
+  auto handle_commands_impl = [this, num_lines, &commands, &options,
+                               &result]() {
+    for (size_t idx = 0; idx < num_lines && !WasInterrupted(); idx++) {
+      const char *cmd = commands.GetStringAtIndex(idx);
+      if (cmd[0] == '\0')
+        continue;
 
-    // We might call into a regex or alias command, in which case the
-    // add_to_history will get lost.  This m_command_source_depth dingus is the
-    // way we turn off adding to the history in that case, so set it up here.
-    if (!options.GetAddToHistory())
-      m_command_source_depth++;
-    bool success = HandleCommand(cmd, options.m_add_to_history, tmp_result);
-    if (!options.GetAddToHistory())
-      m_command_source_depth--;
+      if (options.GetEchoCommands()) {
+        // TODO: Add Stream support.
+        result.AppendMessageWithFormat(
+            "%s %s\n", m_debugger.GetPrompt().str().c_str(), cmd);
+      }
 
-    if (options.GetPrintResults()) {
-      if (tmp_result.Succeeded())
-        result.AppendMessage(tmp_result.GetOutputData());
-    }
+      CommandReturnObject tmp_result(m_debugger.GetUseColor());
+      tmp_result.SetInteractive(result.GetInteractive());
+      tmp_result.SetSuppressImmediateOutput(true);
+
+      // We might call into a regex or alias command, in which case the
+      // add_to_history will get lost.  This m_command_source_depth dingus is
+      // the way we turn off adding to the history in that case, so set it up
+      // here.
+      if (!options.GetAddToHistory())
+        m_command_source_depth++;
+      bool success = HandleCommand(cmd, options.m_add_to_history, tmp_result);
+      if (!options.GetAddToHistory())
+        m_command_source_depth--;
+
+      if (options.GetPrintResults()) {
+        if (tmp_result.Succeeded())
+          result.AppendMessage(tmp_result.GetOutputData());
+      }
 
-    if (!success || !tmp_result.Succeeded()) {
-      llvm::StringRef error_msg = tmp_result.GetErrorData();
-      if (error_msg.empty())
-        error_msg = "<unknown error>.\n";
-      if (options.GetStopOnError()) {
-        result.AppendErrorWithFormat(
-            "Aborting reading of commands after command #%" PRIu64
-            ": '%s' failed with %s",
-            (uint64_t)idx, cmd, error_msg.str().c_str());
-        m_debugger.SetAsyncExecution(old_async_execution);
-        return;
-      } else if (options.GetPrintResults()) {
-        result.AppendMessageWithFormat(
-            "Command #%" PRIu64 " '%s' failed with %s", (uint64_t)idx + 1, cmd,
-            error_msg.str().c_str());
+      if (!success || !tmp_result.Succeeded()) {
+        llvm::StringRef error_msg = tmp_result.GetErrorData();
+        if (error_msg.empty())
+          error_msg = "<unknown error>.\n";
+        if (options.GetStopOnError()) {
+          result.AppendErrorWithFormat(
+              "Aborting reading of commands after command #%" PRIu64
+              ": '%s' failed with %s",
+              (uint64_t)idx, cmd, error_msg.str().c_str());
+          return;
+        } else if (options.GetPrintResults()) {
+          result.AppendMessageWithFormat(
+              "Command #%" PRIu64 " '%s' failed with %s", (uint64_t)idx + 1,
+              cmd, error_msg.str().c_str());
+        }
       }
-    }
 
-    if (result.GetImmediateOutputStream())
-      result.GetImmediateOutputStream()->Flush();
+      if (result.GetImmediateOutputStream())
+        result.GetImmediateOutputStream()->Flush();
+
+      if (result.GetImmediateErrorStream())
+        result.GetImmediateErrorStream()->Flush();
+
+      // N.B. Can't depend on DidChangeProcessState, because the state coming
+      // into the command execution could be running (for instance in Breakpoint
+      // Commands. So we check the return value to see if it is has running in
+      // it.
+      if ((tmp_result.GetStatus() == eReturnStatusSuccessContinuingNoResult) ||
+          (tmp_result.GetStatus() == eReturnStatusSuccessContinuingResult)) {
+        if (options.GetStopOnContinue()) {
+          // If we caused the target to proceed, and we're going to stop in that
+          // case, set the status in our real result before returning.  This is
+          // an error if the continue was not the last command in the set of
+          // commands to be run.
+          if (idx != num_lines - 1)
+            result.AppendErrorWithFormat(
+                "Aborting reading of commands after command #%" PRIu64
+                ": '%s' continued the target.\n",
+                (uint64_t)idx + 1, cmd);
+          else
+            result.AppendMessageWithFormat("Command #%" PRIu64
+                                           " '%s' continued the target.\n",
+                                           (uint64_t)idx + 1, cmd);
 
-    if (result.GetImmediateErrorStream())
-      result.GetImmediateErrorStream()->Flush();
+          result.SetStatus(tmp_result.GetStatus());
+          return;
+        }
+      }
 
-    // N.B. Can't depend on DidChangeProcessState, because the state coming
-    // into the command execution could be running (for instance in Breakpoint
-    // Commands. So we check the return value to see if it is has running in
-    // it.
-    if ((tmp_result.GetStatus() == eReturnStatusSuccessContinuingNoResult) ||
-        (tmp_result.GetStatus() == eReturnStatusSuccessContinuingResult)) {
-      if (options.GetStopOnContinue()) {
-        // If we caused the target to proceed, and we're going to stop in that
-        // case, set the status in our real result before returning.  This is
-        // an error if the continue was not the last command in the set of
-        // commands to be run.
+      // Also check for "stop on crash here:
+      if (tmp_result.GetDidChangeProcessState() && options.GetStopOnCrash() &&
+          DidProcessStopAbnormally()) {
         if (idx != num_lines - 1)
           result.AppendErrorWithFormat(
               "Aborting reading of commands after command #%" PRIu64
-              ": '%s' continued the target.\n",
+              ": '%s' stopped with a signal or exception.\n",
               (uint64_t)idx + 1, cmd);
         else
-          result.AppendMessageWithFormat("Command #%" PRIu64
-                                         " '%s' continued the target.\n",
-                                         (uint64_t)idx + 1, cmd);
+          result.AppendMessageWithFormat(
+              "Command #%" PRIu64 " '%s' stopped with a signal or exception.\n",
+              (uint64_t)idx + 1, cmd);
 
         result.SetStatus(tmp_result.GetStatus());
-        m_debugger.SetAsyncExecution(old_async_execution);
-
         return;
       }
     }
 
-    // Also check for "stop on crash here:
-    if (tmp_result.GetDidChangeProcessState() && options.GetStopOnCrash() &&
-        DidProcessStopAbnormally()) {
-      if (idx != num_lines - 1)
-        result.AppendErrorWithFormat(
-            "Aborting reading of commands after command #%" PRIu64
-            ": '%s' stopped with a signal or exception.\n",
-            (uint64_t)idx + 1, cmd);
-      else
-        result.AppendMessageWithFormat(
-            "Command #%" PRIu64 " '%s' stopped with a signal or exception.\n",
-            (uint64_t)idx + 1, cmd);
-
-      result.SetStatus(tmp_result.GetStatus());
-      m_debugger.SetAsyncExecution(old_async_execution);
-
-      return;
-    }
-  }
+    result.SetStatus(eReturnStatusSuccessFinishResult);
+  };
 
-  result.SetStatus(eReturnStatusSuccessFinishResult);
-  m_debugger.SetAsyncExecution(old_async_execution);
+  // If we are going to continue past a "continue" then we need to run the
+  // commands synchronously.
+  if (!options.GetStopOnContinue())
+    m_debugger.DoWithLockedAsynchronization(false,
+                                            std::move(handle_commands_impl));
+  else
+    handle_commands_impl();
 }
 
 // Make flags that we can pass into the IOHandler so our delegates can do the
@@ -2738,9 +2734,22 @@
   // Asynchronous mode is not supported during reproducer replay.
   if (repro::Reproducer::Instance().GetLoader())
     return;
+
+  std::lock_guard<std::recursive_mutex> lock(m_synchronous_execution_mutex);
   m_synchronous_execution = value;
 }
 
+void CommandInterpreter::DoWithLockedSynchronization(
+    bool synchronous, std::function<void()> &&action) {
+  std::lock_guard<std::recursive_mutex> lock(m_synchronous_execution_mutex);
+  bool old_synchronous = m_synchronous_execution;
+  m_synchronous_execution = synchronous;
+
+  action();
+
+  m_synchronous_execution = old_synchronous;
+}
+
 void CommandInterpreter::OutputFormattedHelpText(Stream &strm,
                                                  llvm::StringRef prefix,
                                                  llvm::StringRef help_text) {
Index: lldb/source/Core/Debugger.cpp
===================================================================
--- lldb/source/Core/Debugger.cpp
+++ lldb/source/Core/Debugger.cpp
@@ -833,6 +833,12 @@
   m_command_interpreter_up->SetSynchronous(!async_execution);
 }
 
+void Debugger::DoWithLockedAsynchronization(bool async,
+                                            std::function<void()> &&action) {
+  m_command_interpreter_up->DoWithLockedSynchronization(!async,
+                                                        std::move(action));
+}
+
 repro::DataRecorder *Debugger::GetInputRecorder() { return m_input_recorder; }
 
 static inline int OpenPipe(int fds[2], std::size_t size) {
Index: lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py
===================================================================
--- lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py
+++ lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py
@@ -11,8 +11,7 @@
 
     def create_debug_adaptor(self, lldbVSCodeEnv=None):
         '''Create the Visual Studio Code debug adaptor'''
-        self.assertTrue(os.path.exists(self.lldbVSCodeExec),
-                        'lldb-vscode must exist')
+        self.assertTrue(is_exe(self.lldbVSCodeExec), 'lldb-vscode must exist')
         log_file_path = self.getBuildArtifact('vscode.txt')
         self.vscode = vscode.DebugAdaptor(
             executable=self.lldbVSCodeExec, init_commands=self.setUpCommands(),
Index: lldb/packages/Python/lldbsuite/test/lldbtest.py
===================================================================
--- lldb/packages/Python/lldbsuite/test/lldbtest.py
+++ lldb/packages/Python/lldbsuite/test/lldbtest.py
@@ -231,6 +231,11 @@
 
 def is_exe(fpath):
     """Returns true if fpath is an executable."""
+    if fpath == None:
+        return False
+    if sys.platform == 'win32':
+        if not fpath.endswith(".exe"):
+            fpath += ".exe"
     return os.path.isfile(fpath) and os.access(fpath, os.X_OK)
 
 
Index: lldb/include/lldb/Interpreter/CommandInterpreter.h
===================================================================
--- lldb/include/lldb/Interpreter/CommandInterpreter.h
+++ lldb/include/lldb/Interpreter/CommandInterpreter.h
@@ -25,6 +25,7 @@
 #include "lldb/lldb-forward.h"
 #include "lldb/lldb-private.h"
 
+#include <functional>
 #include <mutex>
 #include <stack>
 
@@ -626,6 +627,16 @@
 
   void SetSynchronous(bool value);
 
+  /// Invoke the passed function ensuring that the synchronization mode will not
+  /// be changed by any other thread while the function is running.
+  ///
+  /// \param synchronous The mode that should be locked. True means synchronous,
+  ///                    false means asynchronous.
+  /// \param action The function that should be executed while synchronization
+  ///               mode is locked.
+  void DoWithLockedSynchronization(bool synchronous,
+                                   std::function<void()> &&action);
+
   lldb::CommandObjectSP GetCommandSP(llvm::StringRef cmd,
                                      bool include_aliases = true,
                                      bool exact = true,
@@ -678,7 +689,10 @@
   // Execution contexts that were temporarily set by some of HandleCommand*
   // overloads.
   std::stack<ExecutionContext> m_overriden_exe_contexts;
+
   bool m_synchronous_execution;
+  std::recursive_mutex m_synchronous_execution_mutex;
+
   bool m_skip_lldbinit_files;
   bool m_skip_app_init_files;
   CommandObject::CommandMap m_command_dict; // Stores basic built-in commands
Index: lldb/include/lldb/Core/Debugger.h
===================================================================
--- lldb/include/lldb/Core/Debugger.h
+++ lldb/include/lldb/Core/Debugger.h
@@ -11,6 +11,7 @@
 
 #include <cstdint>
 
+#include <functional>
 #include <memory>
 #include <vector>
 
@@ -158,6 +159,15 @@
 
   void SetAsyncExecution(bool async);
 
+  /// Invoke the passed function ensuring that the synchronization mode will not
+  /// be changed by any other thread while the function is running.
+  ///
+  /// \param async The mode that should be locked. True means asynchronous,
+  ///              false means synchronous.
+  /// \param action The function that should be executed while synchronization
+  ///               mode is locked.
+  void DoWithLockedAsynchronization(bool async, std::function<void()> &&action);
+
   lldb::FileSP GetInputFileSP() { return m_input_file_sp; }
 
   lldb::StreamFileSP GetOutputStreamSP() { return m_output_stream_sp; }
_______________________________________________
lldb-commits mailing list
lldb-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits

Reply via email to