Support logpoints in lldb-vscode

This patch implements VSCode DAP logpoints feature (also called tracepoint
in other VS debugger).
This will provide a convenient way for user to do printf style logging
debugging without pausing debuggee.

Differential Revision: https://reviews.llvm.org/D127702

lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/lldbvscode_testcase.py

@@ -22,13 +22,15 @@ class VSCodeTestCaseBase(TestBase):
         self.build()
         self.create_debug_adaptor(lldbVSCodeEnv)
 
-    def set_source_breakpoints(self, source_path, lines, condition=None,
-                               hitCondition=None):
+    def set_source_breakpoints(self, source_path, lines, data=None):
         '''Sets source breakpoints and returns an array of strings containing
            the breakpoint IDs ("1", "2") for each breakpoint that was set.
+           Parameter data is array of data objects for breakpoints.
+           Each object in data is 1:1 mapping with the entry in lines.
+           It contains optional location/hitCondition/logMessage parameters.
         '''
         response = self.vscode.request_setBreakpoints(
-            source_path, lines, condition=condition, hitCondition=hitCondition)
+            source_path, lines, data)
         if response is None:
             return []
         breakpoints = response['body']['breakpoints']

lldb/packages/Python/lldbsuite/test/tools/lldb-vscode/vscode.py

@@ -750,8 +750,11 @@ class DebugCommunication(object):
         }
         return self.send_recv(command_dict)
 
-    def request_setBreakpoints(self, file_path, line_array, condition=None,
-                               hitCondition=None):
+    def request_setBreakpoints(self, file_path, line_array, data=None):
+        ''' data is array of parameters for breakpoints in line_array.
+            Each parameter object is 1:1 mapping with entries in line_entry.
+            It contains optional location/hitCondition/logMessage parameters.
+        '''
         (dir, base) = os.path.split(file_path)
         source_dict = {
             'name': base,
@@ -764,12 +767,18 @@ class DebugCommunication(object):
         if line_array is not None:
             args_dict['lines'] = '%s' % line_array
             breakpoints = []
-            for line in line_array:
+            for i, line in enumerate(line_array):
+                breakpoint_data = None
+                if data is not None and i < len(data):
+                    breakpoint_data = data[i]
                 bp = {'line': line}
-                if condition is not None:
-                    bp['condition'] = condition
-                if hitCondition is not None:
-                    bp['hitCondition'] = hitCondition
+                if breakpoint_data is not None:
+                    if 'condition' in breakpoint_data and breakpoint_data['condition']:
+                        bp['condition'] = breakpoint_data['condition']
+                    if 'hitCondition' in breakpoint_data and breakpoint_data['hitCondition']:
+                        bp['hitCondition'] = breakpoint_data['hitCondition']
+                    if 'logMessage' in breakpoint_data and breakpoint_data['logMessage']:
+                        bp['logMessage'] = breakpoint_data['logMessage']
                 breakpoints.append(bp)
             args_dict['breakpoints'] = breakpoints
 

lldb/test/API/tools/lldb-vscode/breakpoint/TestVSCode_logpoints.py

@@ -0,0 +1,143 @@
+"""
+Test lldb-vscode logpoints feature.
+"""
+
+
+import unittest2
+import vscode
+import shutil
+from lldbsuite.test.decorators import *
+from lldbsuite.test.lldbtest import *
+from lldbsuite.test import lldbutil
+import lldbvscode_testcase
+import os
+
+
+class TestVSCode_logpoints(lldbvscode_testcase.VSCodeTestCaseBase):
+
+    mydir = TestBase.compute_mydir(__file__)
+
+    def setUp(self):
+        lldbvscode_testcase.VSCodeTestCaseBase.setUp(self)
+
+        self.main_basename = 'main-copy.cpp'
+        self.main_path = os.path.realpath(self.getBuildArtifact(self.main_basename))
+
+    @skipIfWindows
+    @skipIfRemote
+    def test_logmessage_basic(self):
+        '''Tests breakpoint logmessage basic functionality.'''
+        before_loop_line = line_number('main.cpp', '// before loop')
+        loop_line = line_number('main.cpp', '// break loop')
+        after_loop_line = line_number('main.cpp', '// after loop')
+
+        program = self.getBuildArtifact("a.out")
+        self.build_and_launch(program)
+
+        # Set a breakpoint at a line before loop
+        before_loop_breakpoint_ids = self.set_source_breakpoints(
+            self.main_path,
+            [before_loop_line])
+        self.assertEquals(len(before_loop_breakpoint_ids), 1, "expect one breakpoint")
+
+        self.vscode.request_continue()
+
+        # Verify we hit the breakpoint before loop line
+        self.verify_breakpoint_hit(before_loop_breakpoint_ids)
+
+        # Swallow old console output
+        self.get_console()
+
+        # Set two breakpoints:
+        # 1. First at the loop line with logMessage
+        # 2. Second guard breakpoint at a line after loop
+        logMessage_prefix = "This is log message for { -- "
+        # Trailing newline is needed for splitlines()
+        logMessage = logMessage_prefix + "{i + 3}\n"
+        [loop_breakpoint_id, post_loop_breakpoint_id] = self.set_source_breakpoints(
+            self.main_path,
+            [loop_line, after_loop_line],
+            [{'logMessage': logMessage}, {}]
+        )
+
+        # Continue to trigger the breakpoint with log messages
+        self.vscode.request_continue()
+
+        # Verify we hit the breakpoint after loop line
+        self.verify_breakpoint_hit([post_loop_breakpoint_id])
+
+        output = self.get_console()
+        lines = output.splitlines()
+        logMessage_output = []
+        for line in lines:
+            if line.startswith(logMessage_prefix):
+                logMessage_output.append(line)
+
+        # Verify logMessage count
+        loop_count = 10
+        self.assertEqual(len(logMessage_output), loop_count)
+
+        # Verify log message match
+        for idx, logMessage_line in enumerate(logMessage_output):
+            result = idx + 3
+            self.assertEqual(logMessage_line, logMessage_prefix + str(result))
+
+
+    @skipIfWindows
+    @skipIfRemote
+    def test_logmessage_advanced(self):
+        '''Tests breakpoint logmessage functionality for complex expression.'''
+        before_loop_line = line_number('main.cpp', '// before loop')
+        loop_line = line_number('main.cpp', '// break loop')
+        after_loop_line = line_number('main.cpp', '// after loop')
+
+        program = self.getBuildArtifact("a.out")
+        self.build_and_launch(program)
+
+        # Set a breakpoint at a line before loop
+        before_loop_breakpoint_ids = self.set_source_breakpoints(
+            self.main_path,
+            [before_loop_line])
+        self.assertEquals(len(before_loop_breakpoint_ids), 1, "expect one breakpoint")
+
+        self.vscode.request_continue()
+
+        # Verify we hit the breakpoint before loop line
+        self.verify_breakpoint_hit(before_loop_breakpoint_ids)
+
+        # Swallow old console output
+        self.get_console()
+
+        # Set two breakpoints:
+        # 1. First at the loop line with logMessage
+        # 2. Second guard breakpoint at a line after loop
+        logMessage_prefix = "This is log message for { -- "
+        # Trailing newline is needed for splitlines()
+        logMessage = logMessage_prefix + "{int y = 0; if (i % 3 == 0) { y = i + 3;} else {y = i * 3;} y}\n"
+        [loop_breakpoint_id, post_loop_breakpoint_id] = self.set_source_breakpoints(
+            self.main_path,
+            [loop_line, after_loop_line],
+            [{'logMessage': logMessage}, {}]
+        )
+
+        # Continue to trigger the breakpoint with log messages
+        self.vscode.request_continue()
+
+        # Verify we hit the breakpoint after loop line
+        self.verify_breakpoint_hit([post_loop_breakpoint_id])
+
+        output = self.get_console()
+        lines = output.splitlines()
+        logMessage_output = []
+        for line in lines:
+            if line.startswith(logMessage_prefix):
+                logMessage_output.append(line)
+
+        # Verify logMessage count
+        loop_count = 10
+        self.assertEqual(len(logMessage_output), loop_count)
+
+        # Verify log message match
+        for idx, logMessage_line in enumerate(logMessage_output):
+            result = idx + 3 if idx % 3 == 0 else idx * 3
+            self.assertEqual(logMessage_line, logMessage_prefix + str(result))

lldb/test/API/tools/lldb-vscode/breakpoint/TestVSCode_setBreakpoints.py

@@ -300,7 +300,7 @@ class TestVSCode_setBreakpoints(lldbvscode_testcase.VSCodeTestCaseBase):
         # Update the condition on our breakpoint
         new_breakpoint_ids = self.set_source_breakpoints(self.main_path,
                                                          [loop_line],
-                                                         condition="i==4")
+                                                         [{'condition': "i==4"}])
         self.assertEquals(breakpoint_ids, new_breakpoint_ids,
                         "existing breakpoint should have its condition "
                         "updated")
@@ -312,7 +312,7 @@ class TestVSCode_setBreakpoints(lldbvscode_testcase.VSCodeTestCaseBase):
 
         new_breakpoint_ids = self.set_source_breakpoints(self.main_path,
                                                          [loop_line],
-                                                         hitCondition="2")
+                                                         [{'hitCondition':"2"}])
 
         self.assertEquals(breakpoint_ids, new_breakpoint_ids,
                         "existing breakpoint should have its condition "

lldb/test/API/tools/lldb-vscode/breakpoint/main.cpp

@@ -33,7 +33,7 @@ int main(int argc, char const *argv[]) {
     fprintf(stderr, "%s\n", dlerror());
     exit(2);
   }
-  foo(12);
+  foo(12); // before loop
 
   for (int i=0; i<10; ++i) {
     int x = twelve(i) + thirteen(i) + a::fourteen(i); // break loop
@@ -43,5 +43,5 @@ int main(int argc, char const *argv[]) {
   } catch (...) {
     puts("caught exception...");
   }
-  return 0;
+  return 0; // after loop
 }

lldb/tools/lldb-vscode/BreakpointBase.cpp

@@ -7,6 +7,7 @@
 //===----------------------------------------------------------------------===//
 
 #include "BreakpointBase.h"
+#include "VSCode.h"
 #include "llvm/ADT/StringExtras.h"
 
 using namespace lldb_vscode;
@@ -24,6 +25,126 @@ void BreakpointBase::SetHitCondition() {
     bp.SetIgnoreCount(hitCount - 1);
 }
 
+// logMessage will be divided into array of LogMessagePart as two kinds:
+// 1. raw print text message, and
+// 2. interpolated expression for evaluation which is inside matching curly
+//    braces.
+//
+// The function tries to parse logMessage into a list of LogMessageParts
+// for easy later access in BreakpointHitCallback.
+void BreakpointBase::SetLogMessage() {
+  logMessageParts.clear();
+
+  // Contains unmatched open curly braces indices.
+  std::vector<int> unmatched_curly_braces;
+
+  // Contains all matched curly braces in logMessage.
+  // Loop invariant: matched_curly_braces_ranges are sorted by start index in
+  // ascending order without any overlap between them.
+  std::vector<std::pair<int, int>> matched_curly_braces_ranges;
+
+  // Part1 - parse matched_curly_braces_ranges.
+  // locating all curly braced expression ranges in logMessage.
+  // The algorithm takes care of nested and imbalanced curly braces.
+  for (size_t i = 0; i < logMessage.size(); ++i) {
+    if (logMessage[i] == '{') {
+      unmatched_curly_braces.push_back(i);
+    } else if (logMessage[i] == '}') {
+      if (unmatched_curly_braces.empty())
+        // Nothing to match.
+        continue;
+
+      int last_unmatched_index = unmatched_curly_braces.back();
+      unmatched_curly_braces.pop_back();
+
+      // Erase any matched ranges included in the new match.
+      while (!matched_curly_braces_ranges.empty()) {
+        assert(matched_curly_braces_ranges.back().first !=
+                   last_unmatched_index &&
+               "How can a curley brace be matched twice?");
+        if (matched_curly_braces_ranges.back().first < last_unmatched_index)
+          break;
+
+        // This is a nested range let's earse it.
+        assert((size_t)matched_curly_braces_ranges.back().second < i);
+        matched_curly_braces_ranges.pop_back();
+      }
+
+      // Assert invariant.
+      assert(matched_curly_braces_ranges.empty() ||
+             matched_curly_braces_ranges.back().first < last_unmatched_index);
+      matched_curly_braces_ranges.emplace_back(last_unmatched_index, i);
+    }
+  }
+
+  // Part2 - parse raw text and expresions parts.
+  // All expression ranges have been parsed in matched_curly_braces_ranges.
+  // The code below uses matched_curly_braces_ranges to divide logMessage
+  // into raw text parts and expression parts.
+  int last_raw_text_start = 0;
+  for (const std::pair<int, int> &curly_braces_range :
+       matched_curly_braces_ranges) {
+    // Raw text before open curly brace.
+    assert(curly_braces_range.first >= last_raw_text_start);
+    size_t raw_text_len = curly_braces_range.first - last_raw_text_start;
+    if (raw_text_len > 0)
+      logMessageParts.emplace_back(
+          llvm::StringRef(logMessage.c_str() + last_raw_text_start,
+                          raw_text_len),
+          /*is_expr=*/false);
+
+    // Expression between curly braces.
+    assert(curly_braces_range.second > curly_braces_range.first);
+    size_t expr_len = curly_braces_range.second - curly_braces_range.first - 1;
+    logMessageParts.emplace_back(
+        llvm::StringRef(logMessage.c_str() + curly_braces_range.first + 1,
+                        expr_len),
+        /*is_expr=*/true);
+    last_raw_text_start = curly_braces_range.second + 1;
+  }
+  // Trailing raw text after close curly brace.
+  if (logMessage.size() > last_raw_text_start)
+    logMessageParts.emplace_back(
+        llvm::StringRef(logMessage.c_str() + last_raw_text_start,
+                        logMessage.size() - last_raw_text_start),
+        /*is_expr=*/false);
+  bp.SetCallback(BreakpointBase::BreakpointHitCallback, this);
+}
+
+/*static*/
+bool BreakpointBase::BreakpointHitCallback(
+    void *baton, lldb::SBProcess &process, lldb::SBThread &thread,
+    lldb::SBBreakpointLocation &location) {
+  if (!baton)
+    return true;
+
+  BreakpointBase *bp = (BreakpointBase *)baton;
+  lldb::SBFrame frame = thread.GetSelectedFrame();
+
+  std::string output;
+  for (const BreakpointBase::LogMessagePart &messagePart :
+       bp->logMessageParts) {
+    if (messagePart.is_expr) {
+      // Try local frame variables first before fall back to expression
+      // evaluation
+      const char *expr = messagePart.text.str().c_str();
+      lldb::SBValue value =
+          frame.GetValueForVariablePath(expr, lldb::eDynamicDontRunTarget);
+      if (value.GetError().Fail())
+        value = frame.EvaluateExpression(expr);
+      const char *expr_val = value.GetValue();
+      if (expr_val)
+        output += expr_val;
+    } else {
+      output += messagePart.text.str();
+    }
+  }
+  g_vsc.SendOutput(OutputType::Console, output.c_str());
+
+  // Do not stop.
+  return false;
+}
+
 void BreakpointBase::UpdateBreakpoint(const BreakpointBase &request_bp) {
   if (condition != request_bp.condition) {
     condition = request_bp.condition;
@@ -33,6 +154,10 @@ void BreakpointBase::UpdateBreakpoint(const BreakpointBase &request_bp) {
     hitCondition = request_bp.hitCondition;
     SetHitCondition();
   }
+  if (logMessage != request_bp.logMessage) {
+    logMessage = request_bp.logMessage;
+    SetLogMessage();
+  }
 }
 
 const char *BreakpointBase::GetBreakpointLabel() {

lldb/tools/lldb-vscode/BreakpointBase.h

@@ -13,11 +13,16 @@
 #include "lldb/API/SBBreakpoint.h"
 #include "llvm/Support/JSON.h"
 #include <string>
+#include <vector>
 
 namespace lldb_vscode {
 
 struct BreakpointBase {
-
+  // logMessage part can be either a raw text or an expression.
+  struct LogMessagePart {
+    llvm::StringRef text;
+    bool is_expr;
+  };
   // An optional expression for conditional breakpoints.
   std::string condition;
   // An optional expression that controls how many hits of the breakpoint are
@@ -27,6 +32,7 @@ struct BreakpointBase {
   // (stop) but log the message instead. Expressions within {} are
   // interpolated.
   std::string logMessage;
+  std::vector<LogMessagePart> logMessageParts;
   // The LLDB breakpoint associated wit this source breakpoint
   lldb::SBBreakpoint bp;
 
@@ -35,8 +41,12 @@ struct BreakpointBase {
 
   void SetCondition();
   void SetHitCondition();
+  void SetLogMessage();
   void UpdateBreakpoint(const BreakpointBase &request_bp);
   static const char *GetBreakpointLabel();
+  static bool BreakpointHitCallback(void *baton, lldb::SBProcess &process,
+                                    lldb::SBThread &thread,
+                                    lldb::SBBreakpointLocation &location);
 };
 
 } // namespace lldb_vscode

lldb/tools/lldb-vscode/FunctionBreakpoint.cpp

@@ -25,6 +25,8 @@ void FunctionBreakpoint::SetBreakpoint() {
     SetCondition();
   if (!hitCondition.empty())
     SetHitCondition();
+  if (!logMessage.empty())
+    SetLogMessage();
 }
 
 } // namespace lldb_vscode

lldb/tools/lldb-vscode/SourceBreakpoint.cpp

@@ -24,6 +24,8 @@ void SourceBreakpoint::SetBreakpoint(const llvm::StringRef source_path) {
     SetCondition();
   if (!hitCondition.empty())
     SetHitCondition();
+  if (!logMessage.empty())
+    SetLogMessage();
 }
 
 } // namespace lldb_vscode

lldb/tools/lldb-vscode/lldb-vscode.cpp

@@ -1532,6 +1532,8 @@ void request_initialize(const llvm::json::Object &request) {
   body.try_emplace("supportsLoadedSourcesRequest", false);
   // The debug adapter supports sending progress reporting events.
   body.try_emplace("supportsProgressReporting", true);
+  // The debug adapter supports 'logMessage' in breakpoint.
+  body.try_emplace("supportsLogPoints", true);
 
   response.try_emplace("body", std::move(body));
   g_vsc.SendJSON(llvm::json::Value(std::move(response)));
@@ -2079,9 +2081,10 @@ void request_setBreakpoints(const llvm::json::Object &request) {
           }
         }
         // At this point the breakpoint is new
-        src_bp.SetBreakpoint(path.data());
-        AppendBreakpoint(src_bp.bp, response_breakpoints, path, src_bp.line);
-        g_vsc.source_breakpoints[path][src_bp.line] = std::move(src_bp);
+        g_vsc.source_breakpoints[path][src_bp.line] = src_bp;
+        SourceBreakpoint &new_bp = g_vsc.source_breakpoints[path][src_bp.line];
+        new_bp.SetBreakpoint(path.data());
+        AppendBreakpoint(new_bp.bp, response_breakpoints, path, new_bp.line);
       }
     }
   }
@@ -2304,10 +2307,11 @@ void request_setFunctionBreakpoints(const llvm::json::Object &request) {
   // Any breakpoints that are left in "request_bps" are breakpoints that
   // need to be set.
   for (auto &pair : request_bps) {
-    pair.second.SetBreakpoint();
     // Add this breakpoint info to the response
-    AppendBreakpoint(pair.second.bp, response_breakpoints);
     g_vsc.function_breakpoints[pair.first()] = std::move(pair.second);
+    FunctionBreakpoint &new_bp = g_vsc.function_breakpoints[pair.first()];
+    new_bp.SetBreakpoint();
+    AppendBreakpoint(new_bp.bp, response_breakpoints);
   }
 
   llvm::json::Object body;