dart-lang/sdk
1
0
Fork 0
Code Issues Pull Requests Actions 3 Packages Projects Releases Wiki Activity

[vm] Improvements for --trace-debugger-stacktrace output.

Browse Source 
Improves the readability of the tracing output by adding beginning and
ending markers for debugger stacktrace collection and using specific
spacing instead of \t in output, so that output is more naturally nested
via indention:
* beginning/ending markers are not indented,
* frames are indented by two spaces, and
* additional output while collecting a frame is indented by four spaces.

Adds tracing for DebuggerStackTrace::CollectAsyncAwaiters(). A different
ending marker is used in the case when the collected trace is discarded
due to a lack of async awaiters.

ActivationFrame::GetSavedCurrentContext now takes an optional out
parameter for the current context variable index, which is only used by
CollectDartFrame and used to print the index there. This eliminates
extra output when this method is used outside collecting stack traces.

When the current context variable index is requested,
GetSavedCurrentContext ignores the cached context if any so that the
index is appropriately set if an appropriate variable is found.

By default, skips tracing of non-collected frames and repeated async
suspensions in async awaiter traces. Use the new
--trace-debugger-stacktrace-verbose flag to add tracing for these cases.

TEST=ci (tested manually, only affects debugging output)

Change-Id: I2978d540f41b444251a61b62a57b6785a3dd8df0
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/467300
Auto-Submit: Tess Strickland <sstrickl@google.com>
Reviewed-by: Alexander Markov <alexmarkov@google.com>
Commit-Queue: Alexander Markov <alexmarkov@google.com>
This commit is contained in:
Tess Strickland
2025-12-10 08:50:30 -08:00
committed by Commit Queue
parent 170df25b66
commit 883859cd4e
2 changed files with 81 additions and 30 deletions
Download Patch File Download Diff File Expand all files Collapse all files
runtime/vm/debugger.cc
+80 -29
View File
@@ -51,6 +51,10 @@ DEFINE_FLAG(bool,
trace_debugger_stacktrace,
false,
"Trace debugger stacktrace collection");
DEFINE_FLAG(bool,
trace_debugger_stacktrace_verbose,
false,
"Additional output when tracing debugger stacktraces");
DEFINE_FLAG(bool, trace_rewind, false, "Trace frame rewind");
DEFINE_FLAG(bool, verbose_debug, false, "Verbose debugger messages");
@@ -774,8 +778,9 @@ bool ActivationFrame::HandlesException(const Instance& exc_obj) {
}
// Get the saved current context of this activation.
const Context& ActivationFrame::GetSavedCurrentContext() {
if (context_initialized_) return ctx_;
const Context& ActivationFrame::GetSavedCurrentContext(intptr_t* index) {
// If the index of the variable was requested, do the retrieval again.
if (context_initialized_ && index == nullptr) return ctx_;
context_initialized_ = true;
GetVarDescriptors();
intptr_t var_desc_len = var_descriptors_.Length();
@@ -785,9 +790,8 @@ const Context& ActivationFrame::GetSavedCurrentContext() {
var_descriptors_.GetInfo(i, &var_info);
const int8_t kind = var_info.kind();
if (kind == UntaggedLocalVarDescriptors::kSavedCurrentContext) {
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("\tFound saved current ctx at index %d\n",
var_info.index());
if (index != nullptr) {
*index = var_info.index();
}
const auto variable_index = VariableIndex(var_info.index());
obj = GetStackVar(variable_index);
@@ -1413,7 +1417,13 @@ void DebuggerStackTrace::AddAsyncSuspension() {
// with stress flags.
if (trace_.is_empty() ||
trace_.Last()->kind() != ActivationFrame::kAsyncSuspensionMarker) {
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr(" async suspension\n");
}
trace_.Add(new ActivationFrame(ActivationFrame::kAsyncSuspensionMarker));
} else if (FLAG_trace_debugger_stacktrace &&
FLAG_trace_debugger_stacktrace_verbose) {
OS::PrintErr(" skipping repeated async suspension\n");
}
}
@@ -1797,9 +1807,15 @@ static ActivationFrame* CollectDartFrame(uword pc,
new ActivationFrame(pc, frame->fp(), frame->sp(), function,
code_or_bytecode, deopt_frame, deopt_frame_offset);
if (FLAG_trace_debugger_stacktrace) {
const Context& ctx = activation->GetSavedCurrentContext();
OS::PrintErr("\tUsing saved context: %s\n", ctx.ToCString());
OS::PrintErr("\tLine number: %" Pd "\n", activation->LineNumber());
intptr_t index = -1;
const Context& ctx = activation->GetSavedCurrentContext(&index);
if (index >= 0) {
OS::PrintErr(" Current context (index %" Pu "): %s\n", index,
ctx.ToCString());
} else if (!ctx.IsNull()) {
OS::PrintErr(" Current context: %s\n", ctx.ToCString());
}
OS::PrintErr(" Line number: %" Pd "\n", activation->LineNumber());
}
return activation;
}
@@ -1836,16 +1852,19 @@ DebuggerStackTrace* DebuggerStackTrace::Collect() {
auto& bytecode = Bytecode::Handle(zone);
DebuggerStackTrace* stack_trace = new DebuggerStackTrace(8);
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("CollectStackTrace: starting collection\n");
}
StackFrameIterator iterator(ValidationPolicy::kDontValidateFrames, thread,
StackFrameIterator::kNoCrossThreadIteration);
for (StackFrame* frame = iterator.NextFrame(); frame != nullptr;
frame = iterator.NextFrame()) {
ASSERT(frame->IsValid());
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("CollectStackTrace: visiting frame:\n\t%s\n",
frame->ToCString());
}
if (frame->IsDartFrame()) {
if (FLAG_trace_debugger_stacktrace) {
// StackFrame::ToCString() prepends two spaces in its output.
OS::PrintErr("%s\n", frame->ToCString());
}
if (frame->is_interpreted()) {
function = frame->LookupDartFunction();
bytecode = frame->LookupDartBytecode();
@@ -1854,8 +1873,17 @@ DebuggerStackTrace* DebuggerStackTrace::Collect() {
code = frame->LookupDartCode();
stack_trace->AppendCodeFrames(frame, code);
}
} else if (FLAG_trace_debugger_stacktrace &&
FLAG_trace_debugger_stacktrace_verbose) {
// StackFrame::ToCString() prepends two spaces in its output.
OS::PrintErr("%s\n", frame->ToCString());
OS::PrintErr(" non-Dart frame skipped\n");
}
}
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("CollectStackTrace: collection finished\n\n");
}
return stack_trace;
}
@@ -1868,9 +1896,8 @@ void DebuggerStackTrace::AppendCodeFrames(StackFrame* frame, const Code& code) {
if (code.is_force_optimized()) {
if (FLAG_trace_debugger_stacktrace) {
ASSERT(!function.IsNull());
OS::PrintErr(
"CollectStackTrace: skipping force-optimized function: %s\n",
function.ToFullyQualifiedCString());
OS::PrintErr(" skipping force-optimized function: %s\n",
function.ToFullyQualifiedCString());
}
return; // Skip frame of force-optimized (and non-debuggable) function.
}
@@ -1882,7 +1909,7 @@ void DebuggerStackTrace::AppendCodeFrames(StackFrame* frame, const Code& code) {
function = it.function();
if (FLAG_trace_debugger_stacktrace) {
ASSERT(!function.IsNull());
OS::PrintErr("CollectStackTrace: visiting inlined function: %s\n",
OS::PrintErr(" visiting inlined function: %s\n",
function.ToFullyQualifiedCString());
}
intptr_t deopt_frame_offset = it.GetDeoptFpOffset();
@@ -1913,6 +1940,9 @@ DebuggerStackTrace* DebuggerStackTrace::CollectAsyncAwaiters() {
constexpr intptr_t kDefaultStackAllocation = 8;
auto stack_trace = new DebuggerStackTrace(kDefaultStackAllocation);
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("CollectStackTrace: starting async awaiters collection\n");
}
bool has_async = false;
bool has_async_catch_error = false;
StackTraceUtils::CollectFrames(
@@ -1923,6 +1953,10 @@ DebuggerStackTrace* DebuggerStackTrace::CollectAsyncAwaiters() {
}
if (frame.frame != nullptr) { // Synchronous portion of the stack.
if (FLAG_trace_debugger_stacktrace) {
// StackFrame::ToCString() prepends two spaces in its output.
OS::PrintErr("%s\n", frame.frame->ToCString());
}
if (!frame.bytecode.IsNull()) {
function = frame.frame->LookupDartFunction();
stack_trace->AppendBytecodeFrame(frame.frame, function,
@@ -1938,37 +1972,54 @@ DebuggerStackTrace* DebuggerStackTrace::CollectAsyncAwaiters() {
return;
}
uword start = 0;
const Object* obj = nullptr;
const char* name = nullptr;
if (!frame.bytecode.IsNull()) {
function = frame.bytecode.function();
ASSERT(!function.IsNull());
if (!function.is_visible()) {
return;
start = frame.bytecode.PayloadStart();
obj = &frame.bytecode;
if (FLAG_trace_debugger_stacktrace) {
name = frame.bytecode.FullyQualifiedName();
}
const uword absolute_pc =
frame.bytecode.PayloadStart() + frame.pc_offset;
stack_trace->AddAsyncAwaiterFrame(absolute_pc, function,
frame.bytecode, frame.closure);
} else {
function = frame.code.function();
if (!function.is_visible()) {
return;
start = frame.code.PayloadStart();
obj = &frame.code;
if (FLAG_trace_debugger_stacktrace) {
name = frame.code.QualifiedName(
NameFormattingParams(Object::kInternalName));
}
const uword absolute_pc =
frame.code.PayloadStart() + frame.pc_offset;
stack_trace->AddAsyncAwaiterFrame(absolute_pc, function, frame.code,
frame.closure);
}
ASSERT(!function.IsNull());
if (!function.is_visible()) {
return;
}
const uword absolute_pc = start + frame.pc_offset;
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr(" async awaiter: %s+%#" Px "\n", name,
frame.pc_offset);
}
stack_trace->AddAsyncAwaiterFrame(absolute_pc, function, *obj,
frame.closure);
}
},
&has_async_catch_error);
// If the entire stack is sync, return no (async) trace.
if (!has_async) {
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr(
"CollectStackTrace: discarding async awaiters collection\n\n");
}
return nullptr;
}
stack_trace->set_has_async_catch_error(has_async_catch_error);
if (FLAG_trace_debugger_stacktrace) {
OS::PrintErr("CollectStackTrace: async awaiters collection finished\n\n");
}
return stack_trace;
}
runtime/vm/debugger.h
+1 -1
View File
@@ -396,7 +396,7 @@ class ActivationFrame : public ZoneAllocated {
ClosurePtr GetClosure();
ObjectPtr GetReceiver();
const Context& GetSavedCurrentContext();
const Context& GetSavedCurrentContext(intptr_t* index = nullptr);
ObjectPtr GetSuspendStateVar();
ObjectPtr GetSuspendableFunctionData();