This is an archive of the discontinued LLVM Phabricator instance.

[lldb-vscode] Send Statistics Dump in terminated event
ClosedPublic

Authored by kusmour on Oct 28 2022, 7:54 PM.

Details

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"}

Diff Detail

Event Timeline

kusmour created this revision.Oct 28 2022, 7:54 PM
Herald added a project: Restricted Project. · View Herald TranscriptOct 28 2022, 7:54 PM
kusmour requested review of this revision.Oct 28 2022, 7:54 PM
kusmour updated this revision to Diff 471725.Oct 29 2022, 12:10 AM
kusmour edited the summary of this revision. (Show Details)
kusmour edited the summary of this revision. (Show Details)
GeorgeHuyubo accepted this revision.Oct 31 2022, 11:49 AM
This revision is now accepted and ready to land.Oct 31 2022, 11:49 AM
clayborg requested changes to this revision.Nov 1 2022, 12:14 PM
clayborg added inline comments.
lldb/tools/lldb-vscode/JSONUtils.cpp
1145

I would remove the NOTE part, as this is what a comment is for. But I would explain this a bit further. Something like:

// Remove any top level dictionaries and arrays from the statistics dump, except for the "targets"
// array. Any top level key/value pairs will be kept.
1158–1160

remove {} on single line if statements (per llvm coding guidelines)

1168

This will crash the debug session if this is reached. Just "break" so we don't crash in case this is ever reached.

1169–1170

We should keep any bools or strings IMHO. Can we add these? I know there isn't anything here, but I could see us maybe adding something like "version" in the future, which could be a string with the LLDB version inside of it.

1171

We have some small dictionaries that we could pass through if we wanted to. One example right now is "memory":

"memory": {
  "strings": {
    "bytesTotal": 3145728,
    "bytesUnused": 1674902,
    "bytesUsed": 1470826
  }
},
1182–1184

remove {} on single line if statements (per llvm coding guidelines)

1188–1190

remove {} on single line if statements (per llvm coding guidelines)

This revision now requires changes to proceed.Nov 1 2022, 12:14 PM
kusmour updated this revision to Diff 472762.Nov 2 2022, 2:17 PM

Addressed comments

  • Grabbed more value types: boolean and string values
  • Removed llvm_unreachable to avoid crashing when we get bad data
  • Fixed format
kusmour updated this revision to Diff 472764.Nov 2 2022, 2:21 PM
kusmour marked 3 inline comments as done.
kusmour marked 3 inline comments as done.
clayborg requested changes to this revision.Nov 3 2022, 11:29 AM

Just one nit for string values not being truncated

lldb/tools/lldb-vscode/JSONUtils.cpp
1170

Don't truncate the string. You can call the API with nullptr and zero to get the length:

// Get the length of the buffer needed to hold the entire string value.
const size_t string_length = value.GetStringValue(nullptr, 0);
// Make a buffer big enough for the entire string
std::string str(string_length+1, 0);
// Read the string
value.GetStringValue(&str[0], string_length);
EmplaceSafeString(...);
This revision now requires changes to proceed.Nov 3 2022, 11:29 AM
kusmour updated this revision to Diff 473011.Nov 3 2022, 1:19 PM
kusmour edited the summary of this revision. (Show Details)

address string type and return the dictionary as well

clayborg requested changes to this revision.Nov 3 2022, 1:50 PM

Just a few quick nits with the new changes

lldb/tools/lldb-vscode/JSONUtils.cpp
1152–1154

Remove braces for single line if. Should we move this info the "case lldb::eStructuredDataTypeArray"?

1163–1164

Do we need this anymore? We either need this or move the modules test here:

if (strcmp(key, "modules") == 0)
  return;
This revision now requires changes to proceed.Nov 3 2022, 1:50 PM
kusmour marked an inline comment as done.Nov 3 2022, 2:13 PM
kusmour added inline comments.
lldb/tools/lldb-vscode/JSONUtils.cpp
1152–1154

Just try to return early if we know we don't want this top level field. I don't think there will be duplicated key anyway.

kusmour updated this revision to Diff 473031.Nov 3 2022, 2:14 PM
kusmour marked an inline comment as done.

address comments

kusmour edited the summary of this revision. (Show Details)Nov 3 2022, 2:15 PM
kusmour marked an inline comment as done.
kusmour added inline comments.
lldb/tools/lldb-vscode/JSONUtils.cpp
1163–1164

I've removed this check. It was originally used to get the targets[0] out of the array as lldb-vscode only debug one target at a time. But to make this code future compatible, let's just do opt-out mode :D

clayborg accepted this revision.Nov 3 2022, 4:31 PM
This revision is now accepted and ready to land.Nov 3 2022, 4:31 PM
kusmour edited the summary of this revision. (Show Details)Nov 3 2022, 6:16 PM
This revision was automatically updated to reflect the committed changes.
kusmour marked an inline comment as done.
Herald added a project: Restricted Project. · View Herald TranscriptNov 3 2022, 6:16 PM
shafik added a subscriber: shafik.Nov 4 2022, 11:52 AM

It looks like this change broke TestVSCode_terminatedEvent.py see Green Dragon build bot: https://green.lab.llvm.org/green/view/LLDB/job/lldb-cmake/48111/

Please fix or revert.

kusmour added a comment.EditedNov 4 2022, 11:59 AM

It looks like this change broke TestVSCode_terminatedEvent.py see Green Dragon build bot: https://green.lab.llvm.org/green/view/LLDB/job/lldb-cmake/48111/

Please fix or revert.

Fixed in: https://reviews.llvm.org/D137455

I will fix test by disabling checking the 'memory' filed. However, when I run the test locally (linux), I got different results, see below:

{"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.0020690000000000001},{\"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.25662499999999999},{\"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.00036600000000000001}],\"expressionEvaluation\":{\"failures\":0,\"successes\":0},\"firstStopTime\":0.16321906999999999,\"frameVariable\":{\"failures\":0,\"successes\":0},\"launchOrAttachTime\":0.124005952,\"moduleIdentifiers\":[94453879969136,94453879680352,94453878991776,139787361446016,139787361476896,139787361522272,139787361656656,139787361825984,139787361883552],\"signals\":[{\"SIGSTOP\":1}],\"sourceMapDeduceCount\":0,\"stopCount\":8,\"targetCreateTime\":0.00060899999999999995,\"totalBreakpointResolveTime\":0.25905999999999996}]","totalDebugInfoByteSize":1668056,"totalDebugInfoEnabled":3,"totalDebugInfoIndexLoadedFromCache":0,"totalDebugInfoIndexSavedToCache":0,"totalDebugInfoIndexTime":0.032538999999999998,"totalDebugInfoParseTime":0.371056,"totalModuleCount":10,"totalModuleCountHasDebugInfo":3,"totalSymbolTableIndexTime":0.051369999999999999,"totalSymbolTableParseTime":0.22812700000000002,"totalSymbolTableStripped":0,"totalSymbolTablesLoadedFromCache":0,"totalSymbolTablesSavedToCache":0},"type":"event"}
--> 
Content-Length: 88

{"command":"disconnect","type":"request","arguments":{"terminateDebuggee":true},"seq":8}
<-- 
Content-Length: 81

{"command":"disconnect","request_seq":8,"seq":0,"success":true,"type":"response"}

========= END =========
PASS: LLDB (/data/users/wanyi/llvm-sand/build/Debug/fbcode-x86_64/toolchain/bin/clang-x86_64) :: test_terminated_event (TestVSCode_terminatedEvent.TestVSCode_terminatedEvent)
----------------------------------------------------------------------
Ran 1 test in 7.237s

RESULT: PASSED (1 passes, 0 failures, 0 errors, 0 skipped, 0 expected failures, 0 unexpected successes)

It looks like this change broke TestVSCode_terminatedEvent.py see Green Dragon build bot: https://green.lab.llvm.org/green/view/LLDB/job/lldb-cmake/48111/

Please fix or revert.

So this issue is a memory ownership issue with the way that llvm::json::Object stores its keys. It uses a llvm::json::ObjectKey which either creates a copy of the string if it is constructed with a std::string or if the string passed in isn't valid UTF8. If you construct a key with a "const char *" or a "llvm::StringRef" then the ObjectKey doesn't own the key string. The issue that happened here was that "void addStatistic(llvm::json::Object &event)" was used to get the statistics from LLDB as a lldb::SBStructuredData object. Then we asked for all top level keys using:

lldb::SBStringList keys;
if (!statistics.GetKeys(keys))
  return;

This is a class that owns a std::vector<std::string> inside of LLDB. Then we called "void FilterAndGetValueForKey(...) and passed it each key:

for (size_t i = 0; i < keys.GetSize(); i++) {
  const char *key = keys.GetStringAtIndex(i);
  FilterAndGetValueForKey(statistics, key, stats_body);
}

Now in FilterAndGetValueForKey(...), for most emplacing of key/value pairs, it was using this:

std::string key_utf8 = llvm::json::fixUTF8(key);

As the key, but some places used the "key" which was a "const char *", which is owned by the "lldb::SBStringList keys" from "addStatistic(...)". These keys are not owned since they were added using the "const char *key", which means as soon as we return from "addStatistic(...)" and then from "CreateTerminatedEventObject()" these string values can change since they are on the heap. It all depends if anyone mallocs memory in the same place that these strings used to live. So depends on the OS and how the allocator works and how busy the allocator is in the current process.