This is an archive of the discontinued LLVM Phabricator instance.

Modify "statistics dump" to dump JSON.
ClosedPublic

Authored by clayborg on Oct 12 2021, 5:33 PM.

Details

Summary

This patch is a smaller version of a previous patch https://reviews.llvm.org/D110804.

This patch modifies the output of "statistics dump" to be able to get stats from the current target. It adds 3 new stats as well. The output of "statistics dump" is now emitted as JSON so that it can be used to track performance and statistics and the output could be used to populate a database that tracks performance. Sample output looks like:

(lldb) statistics dump
{

"expressionEvaluation": {
  "failures": 0,
  "successes": 0
},
"firstStopTime": 0.34164492800000001,
"frameVariable": {
  "failures": 0,
  "successes": 0
},
"launchOrAttachTime": 0.31969605400000001,
"targetCreateTime": 0.0040863039999999998

}

The top level keys are:

"expressionEvaluation" which replaces the previous stats that were emitted as plain text. This dictionary contains the success and fail counts.
"frameVariable" which replaces the previous stats for "frame variable" that were emitted as plain text. This dictionary contains the success and fail counts.
"targetCreateTime" contains the number of seconds it took to create the target and load dependent libraries (if they were enabled) and also will contain symbol preloading times if that setting is enabled.
"launchOrAttachTime" is the time it takes from when the launch/attach is initiated to when the first private stop occurs.
"firstStopTime" is the time in seconds that it takes to stop at the first stop that is presented to the user via the LLDB interface. This value will only have meaning if you set a known breakpoint or stop location in your code that you want to measure as a performance test.

This diff is also meant as a place to discuess what we want out of the "statistics dump" command before adding more funcionality. It is also meant to clean up the previous code that was storting statistics in a vector of numbers within the lldb_private::Target class.

Diff Detail

Event Timeline

clayborg created this revision.Oct 12 2021, 5:33 PM
clayborg requested review of this revision.Oct 12 2021, 5:33 PM
Herald added a project: Restricted Project. · View Herald TranscriptOct 12 2021, 5:33 PM

I have a few comments but I think this is going in a direction that will work for both of us. Once this lands I can sign up for the work to untie the statistics form the target.

lldb/include/lldb/Target/Statistics.h
24

I'd use an enum class with Success and Failure here instead of a bool that requires you to know what the argument is named to know if true means success of failure.

29

I would add a member for the name so that ToJSON can generate the whole JSON object. I imagine something like

SuccessFailStats s("frameVariable");
s.Notify(SuccessFailStats::Success);
s.ToJSON()

which generates

"frameVariable": {
  "failures": 0,
  "successes": 1
},
32

The direction I outlined in the other patch is to move away from tying the statistics to the target. I think the class itself is fine, as long as we agree that the target stats would be held by an object spanning all debuggers.

36

Why don't we have these return an ElapsedTime. Then you can do something like

ElapsedTime elapsed_time = m_stats.GetCreateTime();

RVO should ensure there are no copies, but you can always delete the copy ctor to make sure. Maybe we should call it ScopedTime or something to make it more obvious that this is a RAII object?

52

In line with my earlier comment about not tying the stats tot he target, this would be controlled by the global (singleton) statistic class.

54

I would abstract this behind a TimeStats or TimeStats, similar to SuccessFailStats, so that every type of statistic has its own type.

lldb/include/lldb/Utility/ElapsedTime.h
34 ↗(On Diff #379233)

This seems simple enough and specific enough to the statistics that it can be part of that header?

wallace added inline comments.Oct 13 2021, 10:26 PM
lldb/include/lldb/Target/Process.h
241–242

add a comment saying that this returns the stop id with the value before the bump, otherwise someone might think that this returns the modified value

lldb/include/lldb/Target/Statistics.h
24

Or maybe just NotifySuccess(bool) to keep callers simple

lldb/include/lldb/Target/Target.h
1466–1468

this param is not present

lldb/include/lldb/Utility/ElapsedTime.h
22 ↗(On Diff #379233)
29 ↗(On Diff #379233)
41 ↗(On Diff #379233)
lldb/include/lldb/lldb-forward.h
121 ↗(On Diff #379233)

move this to line ~277

lldb/packages/Python/lldbsuite/test/lldbtest.py
753

is this actually used somewhere?

lldb/source/API/SBTarget.cpp
216–219

a simpler version

lldb/source/Commands/CommandObjectExpression.cpp
661–664

actually this is not sufficient, we need to log as well in the SBAPI side, which is what lldb-vscode uses to evaluate expressions. So either move it to deeper point in the call chain or report this event from other locations

lldb/source/Commands/CommandObjectFrame.cpp
715

same here

clayborg added inline comments.Oct 14 2021, 12:46 PM
lldb/include/lldb/Target/Statistics.h
24

I like the idea of adding:

void NotifySuccess();
void NotifyFailure();

JDevlieghere you ok with that?

29

Good idea!

32

Yeah, my main patch did a little of both. The main idea behind the classes in this file are they don't need to be the storage for the stats, but they can be if that makes things easier. The main classes (Target, Module, Breakpoint, etc) can just have member variables in the main classes themselves, but anything inside of these classes can/should be used in case we want to aggregate stats from any contained Stats classes. For example, I want to have a ModuleStats class (see https://reviews.llvm.org/D110804), this class doesn't not live inside of Module itself, but can be constructed from a Module. Then the TargetStats class can have a std::vector<ModuleStats> classes that it gathers when TargetStats is asked to collect statistics. This same methodology can then be applied to the debugger where we have DebuggerStats.

What do you think of this approach:

  • Any class can define a XXXStats class in this file which is used to collect statistics at any given point
  • Classes can use the XXXStats class as a member variable if it makes sense, or just add member variables to store any objects needed to calculate the stats later when the object is asked to collect stats (target.GatherStatistics(target_stats);).

This would mean we could make a DebuggerStats class that can have a std::vector<TargetStats>, and when the debugger.GatherStatistics(...) is called. Then either the DebuggerStats or TargetStats object can be asked to be converted to JSON when presenting to the user in the "statistics dump" command?

36

These are setting the time at which things start. If we follow suggestions above, SetLaunchOrAttachTime(), SetFirstPrivateStopTime(), and SetFirstPublicStopTime() can be remove and all of the llvm::Optional<std::chrono::steady_clock::time_point> member variables can be moved to Target class, and we can store only "llvm::Optional<ElapsedTime::Duration> launch_or_attach_time;" member variables in the TargetStats class, which would get set when statistics are gathered?

52

I put this here because of the existing SB API:

bool SBTarget::GetCollectingStats();
void SBTarget::SetCollectingStats(bool);

So you want debugger to have this? This m_collecting_stats can be moved to Debugger, or DebuggerStats? But that makes the above API useless or it becomes deprecated. We really don't need to set if we are collecting stats IMHO, since collection should be cheap. You ok with deprecating the "statistics enable"/"statistics disable" and the above APIs?

54

I will make a ElapsedTime::TimePoint

lldb/include/lldb/Target/Target.h
1466–1468

I will remove it!

lldb/include/lldb/Utility/ElapsedTime.h
34 ↗(On Diff #379233)

Yes, good idea.

lldb/include/lldb/lldb-forward.h
121 ↗(On Diff #379233)

I actually need to remove this for now as we don't have this class yet!

lldb/packages/Python/lldbsuite/test/lldbtest.py
753

Not yet, I will remove it

lldb/source/API/SBTarget.cpp
216–219

Will switch!

lldb/source/Commands/CommandObjectExpression.cpp
661–664

Gotcha, will move this.

lldb/source/Commands/CommandObjectFrame.cpp
715

"frame variable" takes optional args. If there are none, it dumps everything which will never fail, if it has args it can be one or more variable names or variable expressions. I can hook into a few more places for this.

clayborg updated this revision to Diff 379860.Oct 14 2021, 3:11 PM

Fixed issues identified in first review round:

  • typos in comments
  • create GlobalStats class to contain the global statistics
  • Make sure all code is using the new StatsClock, StatsDuration, and StatsTimepoint definitions
  • added a "--all-targets" option to dump options to dump stats for all targets and open further discussion

Ok, take a look now. I added a GlobalStats class that contains the "enable/disable" state of the statistics gathering. This shows how things can be organized and dumped.

A few things about the current approach: Stats classes in Statistics.h are designed to be able to be fetched, like TargetStats, and then any class that owns a collection of these, like how GlobalStats could own a std::vector<TargetStats> could then aggregate any sub stats into key/value pairs at this higher level. The original patch will end up gathering ModuleStats for each module in TargetStats, and then collecting total stats for debug info size, debug info parse and index time, symbol table parse and index time, and these total stats can be aggregated and displayed. So hopefully this shows the direction I was thinking. Let me know what you think and what changes you would like to see here.

Right now if you run:
(lldb) statistics dump
It will dump stats for the current target only as one target dictionary. We can change this if desired.
(lldb) statistics dump --all-targets
will dump an dictionary that contains a top level "targets" key/value pair where the value is an array of the all target dictionaries statistics. Of course new key/value pairs can be added to this top level that total up stats from and of the TargetStats statistics.

Friendly ping

rmaz added a subscriber: rmaz.Oct 19 2021, 2:42 PM
JDevlieghere added inline comments.Oct 20 2021, 11:23 AM
lldb/include/lldb/Target/Statistics.h
97

Do we expect there to be something like DebuggerStats? I think it would be nice from a hierarchy perspective that Global Stats have a map of debugger -> to debuggerstat who then in turn hold on to a map of target -> target stats. That hierarchy would work really well for JSON (except they would be lists instead of maps).

98–115

For things like how many lldb_asserts we've hit, this actually will contain its own stats, not just things per debugger and target. I think it makes more sense to make this a Singleton as I did in D110895.

clayborg added inline comments.Oct 20 2021, 2:43 PM
lldb/include/lldb/Target/Statistics.h
97

I can change this to DebuggerStats as this is essentially what this was.

115

This can be expensive if you start locking a mutex just to increment a stat that is a counter and will make statistics slow down the debugger. I would rather rely on std::atomic or the locks already built into Target or Debugger if possible. If lldb_asserts are firing off at a high rate, we can't be spending thousands of instructions locking and unlocking mutexes.

clayborg updated this revision to Diff 381106.Oct 20 2021, 3:21 PM

Rename GlobalStats to DebuggerStats.

JDevlieghere accepted this revision.Oct 21 2021, 10:39 AM

I'm not super happy with the debugger stats as they are right here. Given that it only affects a subset of this patch and I don't want to block other work that depends on this, it's probably easier for me to create a patch on top of this rather than iterating on this one.

LGTM

lldb/include/lldb/Target/Statistics.h
97

I do need something that sits about the debugger for the lldb_assert case.

115

Yeah, and atomic variable for a particular metric might do the trick.

This revision is now accepted and ready to land.Oct 21 2021, 10:39 AM
This revision was automatically updated to reflect the committed changes.
clayborg added a comment.EditedOct 21 2021, 2:00 PM

So there is a buildbot failure due to an expression which succeeds, but because the "expression" command options don't apply cleanly to the expression result the "expression" command fails. Question: do we want "expressionEvaluation" to truly track expression evaluation failures, or just track the "expression" command success and fails? I updated this patch to track expression failures only by modifying the Target::EvaluateExpression(), so if this succeeds and "expr" command fails, we consider the expression a success right now.

So there is a buildbot failure due to an expression which succeeds, but because the "expression" command options don't apply cleanly to the expression result the "expression" command fails. Question: do we want "expressionEvaluation" to truly track expression evaluation failures, or just track the "expression" command success and fails? I updated this patch to track expression failures only by modifying the Target::EvaluateExpression(), so if this succeeds and "expr" command fails, we consider the expression a success right now.

I have to look into this but could we skip that test in the meantime?

There is also another failure that looks like it's caused by some accidental change (see inline)

lldb/packages/Python/lldbsuite/test/lldbtest.py
753

I think you also removed some existing stuff here:

PASS: LLDB (C:\buildbot\lldb-x64-windows-ninja\build\bin\clang.exe-x86_64) :: test_zero_uuid_modules (TestMiniDumpUUID.MiniDumpUUIDTestCase)
======================================================================
ERROR: test_relative_module_name (TestMiniDumpUUID.MiniDumpUUIDTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\buildbot\lldb-x64-windows-ninja\llvm-project\lldb\test\API\functionalities\postmortem\minidump-new\TestMiniDumpUUID.py", line 317, in test_relative_module_name
    self.getSourcePath("relative_module_name.yaml"))
AttributeError: 'MiniDumpUUIDTestCase' object has no attribute 'getSourcePath'
Config=x86_64-C:\buildbot\lldb-x64-windows-ninja\build\bin\clang.exe

So there is a buildbot failure due to an expression which succeeds, but because the "expression" command options don't apply cleanly to the expression result the "expression" command fails. Question: do we want "expressionEvaluation" to truly track expression evaluation failures, or just track the "expression" command success and fails? I updated this patch to track expression failures only by modifying the Target::EvaluateExpression(), so if this succeeds and "expr" command fails, we consider the expression a success right now.

I have to look into this but could we skip that test in the meantime?

There is also another failure that looks like it's caused by some accidental change (see inline)''

I will check in a fix in a few minutes for my buildbot issues.

Fixed buildbots with:

commit 910838f07da7872d2b7cca5b07d64ea9915b6767 (HEAD -> main, origin/main, origin/HEAD)
Author: Greg Clayton <gclayton@fb.com>
Date: Thu Oct 21 14:21:36 2021 -0700

Fix buildbots after https://reviews.llvm.org/D111686