[lldb-vscode] Send Selected Statistics Dump in Terminated Event

[kusmour]

Summary

This patch will gather debug info & breakpoint info from the statistics dump (from (SBTarget.GetStatistics()) func) and send to DAP in terminated event.

The statistics content can be huge (especially the modules) and dumping in full JSON can create delay in the IDE's debugging UI. (For more details, please read: https://github.com/llvm/llvm-project/commit/7bbd0fba986c241162b77b7e424ad82bc7e17b41 ). Hence, we will filter out large contents before returning it in terminated event.

It will keep all the metadata fields (those starts with "total"). For large contents, it uses the opt-out strategy. Currently it only removes the "modules" field. This way every time a new top-level field being added, we will be able to capture them from DAP log without changing lldb-vscode.

The DAP terminated event should look like

{
  "event":"terminated",
  "seq":0,
  "statistics": {
    "memory": <JSON string>
    "targets": <JSON string>, // it's a JSON array, breakpoints info included in each target
    <metadata_key: value> // pairs
  },
  "type":"event"
}

All the info above will be append to statistics field in the terminated event

Test Plan

Debugged a simple hello world program from VSCode. Exit debug session in two ways: 1) run to program exit; 2) user initiated debug session end (quit debugging before program exit).
Check DAP log and see both debug sessions have statistics returned in terminated event.

Here's an example when debugging the test program:

{"event":"terminated","seq":0,"statistics":{"memory":"{\"strings\":{\"bytesTotal\":1843200,\"bytesUnused\":897741,\"bytesUsed\":945459}}","targets":"[{\"breakpoints\":[{\"details\":{\"Breakpoint\":{\"BKPTOptions\":{\"AutoContinue\":false,\"ConditionText\":\"\",\"EnabledState\":true,\"IgnoreCount\":0,\"OneShotState\":false},\"BKPTResolver\":{\"Options\":{\"NameMask\":[56],\"Offset\":0,\"SkipPrologue\":true,\"SymbolNames\":[\"foo\"]},\"Type\":\"SymbolName\"},\"Hardware\":false,\"Names\":[\"vscode\"],\"SearchFilter\":{\"Options\":{},\"Type\":\"Unconstrained\"}}},\"id\":1,\"internal\":false,\"numLocations\":1,\"numResolvedLocations\":1,\"resolveTime\":0.002232},{\"details\":{\"Breakpoint\":{\"BKPTOptions\":{\"AutoContinue\":false,\"ConditionText\":\"\",\"EnabledState\":true,\"IgnoreCount\":0,\"OneShotState\":false},\"BKPTResolver\":{\"Options\":{\"Column\":0,\"Exact\":false,\"FileName\":\"/data/users/wanyi/llvm-sand/external/llvm-project/lldb/test/API/tools/lldb-vscode/terminated-event/main.cpp\",\"Inlines\":true,\"LineNumber\":5,\"Offset\":0,\"SkipPrologue\":true},\"Type\":\"FileAndLine\"},\"Hardware\":false,\"Names\":[\"vscode\"],\"SearchFilter\":{\"Options\":{},\"Type\":\"Unconstrained\"}}},\"id\":2,\"internal\":false,\"numLocations\":0,\"numResolvedLocations\":0,\"resolveTime\":0.23203799999999999},{\"details\":{\"Breakpoint\":{\"BKPTOptions\":{\"AutoContinue\":false,\"ConditionText\":\"\",\"EnabledState\":true,\"IgnoreCount\":0,\"OneShotState\":false},\"BKPTResolver\":{\"Options\":{\"Language\":\"c\",\"NameMask\":[4,4,4,4,4,4],\"Offset\":0,\"SkipPrologue\":false,\"SymbolNames\":[\"_dl_debug_state\",\"rtld_db_dlactivity\",\"__dl_rtld_db_dlactivity\",\"r_debug_state\",\"_r_debug_state\",\"_rtld_debug_state\"]},\"Type\":\"SymbolName\"},\"Hardware\":false,\"SearchFilter\":{\"Options\":{\"ModuleList\":[\"/usr/lib64/ld-2.28.so\"]},\"Type\":\"Modules\"}}},\"id\":-1,\"internal\":true,\"kindDescription\":\"shared-library-event\",\"numLocations\":1,\"numResolvedLocations\":1,\"resolveTime\":0.00026699999999999998}],\"expressionEvaluation\":{\"failures\":0,\"successes\":0},\"firstStopTime\":0.087458974999999994,\"frameVariable\":{\"failures\":0,\"successes\":0},\"launchOrAttachTime\":0.052953161999999998,\"moduleIdentifiers\":[94554748126576,94554747837792,94554747149216,139800112130176,139800112161056,139800112206064,139800112340224,139800112509552,139800112236528],\"signals\":[{\"SIGSTOP\":1}],\"sourceMapDeduceCount\":0,\"stopCount\":8,\"targetCreateTime\":0.00057700000000000004,\"totalBreakpointResolveTime\":0.234537}]","totalDebugInfoByteSize":1668056,"totalDebugInfoEnabled":3,"totalDebugInfoIndexLoadedFromCache":0,"totalDebugInfoIndexSavedToCache":0,"totalDebugInfoIndexTime":0.027963000000000002,"totalDebugInfoParseTime":0.34354800000000002,"totalModuleCount":10,"totalModuleCountHasDebugInfo":3,"totalSymbolTableIndexTime":0.056050000000000003,"totalSymbolTableParseTime":0.23930000000000001,"totalSymbolTableStripped":0,"totalSymbolTablesLoadedFromCache":0,"totalSymbolTablesSavedToCache":0},"type":"event"}

[clayborg]

The key change here is we always use a "std::string key_utf8" as the keys which means that the llvm JSON parser will make a copy of the key string value internally to avoid the issues we ran into before.

Looks good

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

def wait_for_stopped(self, timeout=None):
             stopped_event = self.wait_for_event(filter='stopped', timeout=0.25)
         if exited:
             self.threads = []
         return stopped_events
 
     def wait_for_exited(self):
         event_dict = self.wait_for_event('exited')
         if event_dict is None:
-            raise ValueError("didn't get stopped event")
+            raise ValueError("didn't get exited event")
+        return event_dict
+
+    def wait_for_terminated(self):
+        event_dict = self.wait_for_event('terminated')
+        if event_dict is None:
+            raise ValueError("didn't get terminated event")
         return event_dict
 
     def get_initialize_value(self, key):
         '''Get a value for the given key if it there is a key/value pair in
            the "initialize" request response body.
         '''
         if self.initialize_body and key in self.initialize_body:
             return self.initialize_body[key]

lldb/test/API/tools/lldb-vscode/terminated-event/Makefile

+DYLIB_NAME := foo
+DYLIB_CXX_SOURCES := foo.cpp
+CXX_SOURCES := main.cpp
+
+LD_EXTRAS := -Wl,-rpath "-Wl,$(shell pwd)"
+USE_LIBDL :=1
+
+include Makefile.rules
+
+all: a.out.stripped
+
+a.out.stripped:
+  strip -o a.out.stripped a.out
+
+ifneq "$(CODESIGN)" ""
+  $(CODESIGN) -fs - a.out.stripped
+endif
 No newline at end of file

lldb/test/API/tools/lldb-vscode/terminated-event/TestVSCode_terminatedEvent.py

+"""
+Test lldb-vscode terminated event
+"""
+
+import vscode
+from lldbsuite.test.decorators import *
+from lldbsuite.test.lldbtest import *
+from lldbsuite.test import lldbutil
+import lldbvscode_testcase
+import re
+import json
+
+class TestVSCode_terminatedEvent(lldbvscode_testcase.VSCodeTestCaseBase):
+
+    @skipIfWindows
+    @skipIfRemote
+    def test_terminated_event(self):
+        '''
+            Terminated Event
+            Now contains the statistics of a debug session:
+            metatdata:
+                totalDebugInfoByteSize > 0
+                totalDebugInfoEnabled > 0
+                totalModuleCountHasDebugInfo > 0
+                ...
+            targetInfo:
+                totalBreakpointResolveTime > 0
+            breakpoints:
+                recognize function breakpoint
+                recognize source line breakpoint
+            It should contains the breakpoints info: function bp & source line bp
+        '''
+
+        program_basename = "a.out.stripped"
+        program = self.getBuildArtifact(program_basename)
+        self.build_and_launch(program)
+        # Set breakpoints
+        functions = ['foo']
+        breakpoint_ids = self.set_function_breakpoints(functions)
+        self.assertEquals(len(breakpoint_ids), len(functions), 'expect one breakpoint')
+        main_bp_line = line_number('main.cpp', '// main breakpoint 1')
+        breakpoint_ids.append(self.set_source_breakpoints('main.cpp', [main_bp_line]))
+
+        self.continue_to_breakpoints(breakpoint_ids)
+        self.continue_to_exit()
+
+        statistics = self.vscode.wait_for_terminated()['statistics']
+        self.assertTrue(statistics['totalDebugInfoByteSize'] > 0)
+        self.assertTrue(statistics['totalDebugInfoEnabled'] > 0)
+        self.assertTrue(statistics['totalModuleCountHasDebugInfo'] > 0)
+
+        self.assertIsNotNone(statistics['memory'])
+        self.assertNotIn('modules', statistics.keys())
+
+        # lldb-vscode debugs one target at a time
+        target = json.loads(statistics['targets'])[0]
+        self.assertTrue(target['totalBreakpointResolveTime'] > 0)
+
+        breakpoints = target['breakpoints']
+        self.assertIn('foo',
+                      breakpoints[0]['details']['Breakpoint']['BKPTResolver']['Options']['SymbolNames'],
+                      'foo is a symbol breakpoint')
+        self.assertTrue(breakpoints[1]['details']['Breakpoint']['BKPTResolver']['Options']['FileName'].endswith('main.cpp'),
+                        'target has source line breakpoint in main.cpp')

lldb/test/API/tools/lldb-vscode/terminated-event/foo.h

+int foo();

lldb/test/API/tools/lldb-vscode/terminated-event/foo.cpp

+int foo() {
+    return 12;
+}

lldb/test/API/tools/lldb-vscode/terminated-event/main.cpp

+#include <iostream>
+#include "foo.h"
+
+int main(int argc, char const *argv[]) {
+  std::cout << "Hello World!" << std::endl; // main breakpoint 1
+  foo();
+  return 0;
+}

lldb/tools/lldb-vscode/JSONUtils.h

 /// \return
 ///     A "runInTerminal" JSON object that follows the specification outlined by
 ///     Microsoft.
 llvm::json::Object
 CreateRunInTerminalReverseRequest(const llvm::json::Object &launch_request,
                                   llvm::StringRef debug_adaptor_path,
                                   llvm::StringRef comm_file);
 
+/// Create a "Terminated" JSON object that contains statistics
+///
+/// \return
+///     A body JSON object with debug info and breakpoint info
+llvm::json::Object CreateTerminatedEventObject();
+
 /// Convert a given JSON object to a string.
 std::string JSONToString(const llvm::json::Value &json);
 
 } // namespace lldb_vscode
 
 #endif

lldb/tools/lldb-vscode/JSONUtils.cpp

 #include "llvm/ADT/Optional.h"
 #include "llvm/Support/FormatAdapters.h"
 #include "llvm/Support/Path.h"
 #include "llvm/Support/ScopedPrinter.h"
 
 #include "lldb/API/SBBreakpoint.h"
 #include "lldb/API/SBBreakpointLocation.h"
 #include "lldb/API/SBDeclaration.h"
+#include "lldb/API/SBStringList.h"
+#include "lldb/API/SBStructuredData.h"
 #include "lldb/API/SBValue.h"
 #include "lldb/Host/PosixApi.h"
 
 #include "ExceptionBreakpoint.h"
 #include "JSONUtils.h"
 #include "LLDBUtils.h"
 #include "VSCode.h"
 
CreateRunInTerminalReverseRequest(const llvm::json::Object &launch_request,
   run_in_terminal_args.try_emplace("env",
                                    llvm::json::Value(std::move(environment)));
 
   reverse_request.try_emplace(
       "arguments", llvm::json::Value(std::move(run_in_terminal_args)));
   return reverse_request;
 }
 
+// Keep all the top level items from the statistics dump, except for the
+// "modules" array. It can be huge and cause delay
+// Array and dictionary value will return as <key, JSON string> pairs
+void FilterAndGetValueForKey(const lldb::SBStructuredData data, const char *key,
+                             llvm::json::Object &out) {
+  lldb::SBStructuredData value = data.GetValueForKey(key);
+  std::string key_utf8 = llvm::json::fixUTF8(key);
+  if (strcmp(key, "modules") == 0)
+    return;
+  switch (value.GetType()) {
+  case lldb::eStructuredDataTypeFloat:
+    out.try_emplace(key_utf8, value.GetFloatValue());
+    break;
+  case lldb::eStructuredDataTypeInteger:
+    out.try_emplace(key_utf8, value.GetIntegerValue());
+    break;
+  case lldb::eStructuredDataTypeArray: {
+    lldb::SBStream contents;
+    value.GetAsJSON(contents);
+    out.try_emplace(key_utf8, llvm::json::fixUTF8(contents.GetData()));
+  } break;
+  case lldb::eStructuredDataTypeBoolean:
+    out.try_emplace(key_utf8, value.GetBooleanValue());
+    break;
+  case lldb::eStructuredDataTypeString: {
+    // Get the string size before reading
+    const size_t str_length = value.GetStringValue(nullptr, 0);
+    std::string str(str_length + 1, 0);
+    value.GetStringValue(&str[0], str_length);
+    out.try_emplace(key_utf8, llvm::json::fixUTF8(str));
+  } break;
+  case lldb::eStructuredDataTypeDictionary: {
+    lldb::SBStream contents;
+    value.GetAsJSON(contents);
+    out.try_emplace(key_utf8, llvm::json::fixUTF8(contents.GetData()));
+  } break;
+  case lldb::eStructuredDataTypeNull:
+  case lldb::eStructuredDataTypeGeneric:
+  case lldb::eStructuredDataTypeInvalid:
+    break;
+  }
+}
+
+void addStatistic(llvm::json::Object &event) {
+  lldb::SBStructuredData statistics = g_vsc.target.GetStatistics();
+  bool is_dictionary =
+      statistics.GetType() == lldb::eStructuredDataTypeDictionary;
+  if (!is_dictionary)
+    return;
+  llvm::json::Object stats_body;
+
+  lldb::SBStringList keys;
+  if (!statistics.GetKeys(keys))
+    return;
+  for (size_t i = 0; i < keys.GetSize(); i++) {
+    const char *key = keys.GetStringAtIndex(i);
+    FilterAndGetValueForKey(statistics, key, stats_body);
+  }
+  event.try_emplace("statistics", std::move(stats_body));
+}
+
+llvm::json::Object CreateTerminatedEventObject() {
+  llvm::json::Object event(CreateEventObject("terminated"));
+  addStatistic(event);
+  return event;
+}
+
 std::string JSONToString(const llvm::json::Value &json) {
   std::string data;
   llvm::raw_string_ostream os(data);
   os << json;
   os.flush();
   return data;
 }
 
 } // namespace lldb_vscode

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

void SendTerminatedEvent() {
   // that might've been generated by the execution of terminateCommands. So,
   // synchronize simultaneous calls to SendTerminatedEvent.
   static std::mutex mutex;
   std::lock_guard<std::mutex> locker(mutex);
   if (!g_vsc.sent_terminated_event) {
     g_vsc.sent_terminated_event = true;
     g_vsc.RunTerminateCommands();
     // Send a "terminated" event
-    llvm::json::Object event(CreateEventObject("terminated"));
+    llvm::json::Object event(CreateTerminatedEventObject());
     g_vsc.SendJSON(llvm::json::Value(std::move(event)));
   }
 }
 
 // Send a thread stopped event for all threads as long as the process
 // is stopped.
 void SendThreadStoppedEvent() {
   lldb::SBProcess process = g_vsc.target.GetProcess();
if (variablesReference == VARREF_REGS) {
       // Change the default format of any pointer sized registers in the first
       // register set to be the lldb::eFormatAddressInfo so we show the pointer
       // and resolve what the pointer resolves to. Only change the format if the
       // format was set to the default format or if it was hex as some registers
       // have formats set for them.
       const uint32_t addr_size = g_vsc.target.GetProcess().GetAddressByteSize();
       lldb::SBValue reg_set = g_vsc.variables.registers.GetValueAtIndex(0);
       const uint32_t num_regs = reg_set.GetNumChildren();
-      for (uint32_t reg_idx=0; reg_idx<num_regs; ++reg_idx) {
+      for (uint32_t reg_idx = 0; reg_idx < num_regs; ++reg_idx) {
         lldb::SBValue reg = reg_set.GetChildAtIndex(reg_idx);
         const lldb::Format format = reg.GetFormat();
         if (format == lldb::eFormatDefault || format == lldb::eFormatHex) {
           if (reg.GetByteSize() == addr_size)
             reg.SetFormat(lldb::eFormatAddressInfo);
         }
       }
     }