[lldb-vscode] Send Statistics Dump in terminated event

[kusmour]

Summary

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

We will return full contents of statistics dump (SBTarget.GetStatistics()) as a JSON string. So that every time a new field being added, we will be able to capture them from DAP log without changing lldb-vscode.

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\":1851392,\"bytesUnused\":905933,\"bytesUsed\":945459}},\"modules\":[{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":93901655961472,\"path\":\"/data/users/wanyi/llvm-sand/build/Debug/fbcode-x86_64/toolchain/lldb-test-build.noindex/tools/lldb-vscode/terminated-event/TestVSCode_terminatedEvent.test_terminated_event/a.out.stripped\",\"symbolTableIndexTime\":0.00067299999999999999,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.00054799999999999998,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"E317E50F\"},{\"debugInfoByteSize\":833593,\"debugInfoEnabled\":true,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0.012657,\"debugInfoParseTime\":0.32714500000000002,\"identifier\":93901656106336,\"path\":\"/usr/lib64/ld-2.28.so\",\"symbolTableIndexTime\":0.0017719999999999999,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.025423000000000001,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"57D782C6-AF24-135E-6970-7B9D3334B91B-6CD33392\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":93901654578688,\"path\":\"[vdso](0x00007ffff7ffd000)\",\"symbolTableIndexTime\":3.1000000000000001e-05,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.00038900000000000002,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64-unknown-linux-gnu\",\"uuid\":\"B5AF4022-69CE-E598-5703-F5C62C32322D-D9CF26D1\"},{\"debugInfoByteSize\":1020,\"debugInfoEnabled\":true,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0.0021559999999999999,\"debugInfoParseTime\":0.00024699999999999999,\"identifier\":140008887806080,\"path\":\"/data/users/wanyi/llvm-sand/build/Debug/fbcode-x86_64/toolchain/lldb-test-build.noindex/tools/lldb-vscode/terminated-event/TestVSCode_terminatedEvent.test_terminated_event/libfoo.so\",\"symbolTableIndexTime\":6.2000000000000003e-05,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.00080800000000000002,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--\",\"uuid\":\"109BFB15\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":140008887859888,\"path\":\"/lib64/libdl.so.2\",\"symbolTableIndexTime\":0.000105,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.0013470000000000001,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"776BF255-7FD5-1D1A-CAB0-D1D2D7568263-EC5999B5\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":140008887883408,\"path\":\"/lib64/libstdc++.so.6\",\"symbolTableIndexTime\":0.038710000000000001,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.075740000000000002,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"104D4081-3FC7-4F42-7CD4-AC714B249C02-DA5E62C3\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":140008887951248,\"path\":\"/lib64/libm.so.6\",\"symbolTableIndexTime\":0.003212,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.027257,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"089E6D24-BF02-DE2B-C57E-456118BFDC1D-691B14BB\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":140008888170224,\"path\":\"/lib64/libgcc_s.so.1\",\"symbolTableIndexTime\":0.000357,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.0040460000000000001,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--\",\"uuid\":\"CD2F6200-D8CA-7045-ADDB-17C6C4240AAC-5DE305B1\"},{\"debugInfoByteSize\":0,\"debugInfoEnabled\":false,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0,\"debugInfoParseTime\":0,\"identifier\":140008887911072,\"path\":\"/lib64/libc.so.6\",\"symbolTableIndexTime\":0.0070210000000000003,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.072236999999999996,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"F65C85BF-DB90-4B62-3D4F-E2139B4D7C25-CF8C0B58\"},{\"debugInfoByteSize\":833593,\"debugInfoEnabled\":true,\"debugInfoIndexLoadedFromCache\":false,\"debugInfoIndexSavedToCache\":false,\"debugInfoIndexTime\":0.012407,\"debugInfoParseTime\":0.012078999999999999,\"identifier\":140008887927648,\"path\":\"/lib64/ld-linux-x86-64.so.2\",\"symbolTableIndexTime\":0.001758,\"symbolTableLoadedFromCache\":false,\"symbolTableParseTime\":0.022352,\"symbolTableSavedToCache\":false,\"symbolTableStripped\":false,\"triple\":\"x86_64--linux\",\"uuid\":\"57D782C6-AF24-135E-6970-7B9D3334B91B-6CD33392\"}],\"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.0020110000000000002},{\"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.22744400000000001},{\"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.00034600000000000001}],\"expressionEvaluation\":{\"failures\":0,\"successes\":0},\"firstStopTime\":0.157499681,\"frameVariable\":{\"failures\":0,\"successes\":0},\"launchOrAttachTime\":0.117741226,\"moduleIdentifiers\":[93901655961472,93901656106336,93901654578688,140008887806080,140008887859888,140008887883408,140008887951248,140008888170224,140008887911072],\"signals\":[{\"SIGSTOP\":1}],\"sourceMapDeduceCount\":0,\"stopCount\":8,\"targetCreateTime\":0.00064000000000000005,\"totalBreakpointResolveTime\":0.22980100000000003}],\"totalDebugInfoByteSize\":1668206,\"totalDebugInfoEnabled\":3,\"totalDebugInfoIndexLoadedFromCache\":0,\"totalDebugInfoIndexSavedToCache\":0,\"totalDebugInfoIndexTime\":0.027220000000000001,\"totalDebugInfoParseTime\":0.33947100000000002,\"totalModuleCount\":10,\"totalModuleCountHasDebugInfo\":3,\"totalSymbolTableIndexTime\":0.053701000000000006,\"totalSymbolTableParseTime\":0.23014699999999999,\"totalSymbolTableStripped\":0,\"totalSymbolTablesLoadedFromCache\":0,\"totalSymbolTablesSavedToCache\":0}","type":"event"}

[bulbazord]

Something you may want to do is update this with a new revision that has more context. Notice how all the files in your change are surrounded by "Context not available.".

If you uploaded your change as a .diff file, you could do something like git show -U999999999 > my.patch instead of just git show > my.patch. More details here: https://llvm.org/docs/Phabricator.html#requesting-a-review-via-the-web-interface

[kusmour]

Rebase onto upstream/main and create patch with more context

[clayborg]

lldb/tools/lldb-vscode/JSONUtils.cpp

1171–1185

Does it take too much time to encode the entire statistics dump output into the terminated event? I would love to have all of the data if possible. Otherwise each time we add a new statistic to the "statistics dump" command we will need to update this code?

lldb/tools/lldb-vscode/VSCode.h

46 ↗

(On Diff #470270)

This can probably be moved into JSONUtils.cpp right? I don't see SBStructuredData being used in any header files.

[yinghuitan]

lldb/tools/lldb-vscode/JSONUtils.cpp

1171–1185

@clayborg, it can take half minute for really big target like AdFinder. However, @kusmour since we are using the new synchronization in VSCode to wait terminated statistics for telemetry and we know delayed terminated event won't block VSCode maybe we should send everything as Greg suggested?

[kusmour]

address comments to return the whole statistics dump in terminated event

[clayborg]

Thanks for the changes! Looks good to me.

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 = json.loads(self.vscode.wait_for_terminated()['statistics'])
+        self.assertTrue(statistics['totalDebugInfoByteSize'] > 0)
+        self.assertTrue(statistics['totalDebugInfoEnabled'] > 0)
+        self.assertTrue(statistics['totalModuleCountHasDebugInfo'] > 0)
+
+        # lldb-vscode debugs one target at a time
+        self.assertTrue(statistics['targets'][0]['totalBreakpointResolveTime'] > 0)
+
+        breakpoints = statistics['targets'][0]['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/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;
 }
 
+llvm::json::Object CreateTerminatedEventObject() {
+  llvm::json::Object event(CreateEventObject("terminated"));
+  lldb::SBStructuredData statistics = g_vsc.target.GetStatistics();
+  bool is_dictionary =
+      statistics.GetType() == lldb::eStructuredDataTypeDictionary;
+  if (!is_dictionary) {
+    return event;
+  }
+
+  lldb::SBStream stats_stream;
+  statistics.GetAsJSON(stats_stream);
+  event.try_emplace("statistics", llvm::json::fixUTF8(stats_stream.GetData()));
+  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();