[debugger] Added debug lib + BlockTimer
Created a new sub-library within debug_ipc so that other libraries, like
elflib, can depend on this debug tools without a circular dependency.
Added a BlockTimer class which logs the time from creation until the
call to EndTimer. EndTimer is implicitly called on destruction.
Added a global debug flag that will control the behaviour of these debug
tools. Added also time information since the beginning of the program.
This is useful to see timing differences between log statements.
Removed the debug mode from the MessageLoop, as now that behavior is
handled by the timer.
Instrumented common blocks.
TEST=manual
Change-Id: Ib379901e9a1e22869030e380a44a7e078162194f
diff --git a/garnet/bin/debug_agent/arch_arm64_helpers_unittest.cc b/garnet/bin/debug_agent/arch_arm64_helpers_unittest.cc
index 9c5911f..4af18a5 100644
--- a/garnet/bin/debug_agent/arch_arm64_helpers_unittest.cc
+++ b/garnet/bin/debug_agent/arch_arm64_helpers_unittest.cc
@@ -8,7 +8,7 @@
#include <optional>
-#include "garnet/lib/debug_ipc/helper/file_line_function.h"
+#include "garnet/lib/debug_ipc/debug/file_line_function.h"
#include "garnet/lib/debug_ipc/helper/zx_status.h"
#include "lib/fxl/arraysize.h"
diff --git a/garnet/bin/debug_agent/arch_x64_helpers_unittest.cc b/garnet/bin/debug_agent/arch_x64_helpers_unittest.cc
index 5c2b72d..1cea12b 100644
--- a/garnet/bin/debug_agent/arch_x64_helpers_unittest.cc
+++ b/garnet/bin/debug_agent/arch_x64_helpers_unittest.cc
@@ -6,7 +6,7 @@
#include <gtest/gtest.h>
-#include "garnet/lib/debug_ipc/helper/file_line_function.h"
+#include "garnet/lib/debug_ipc/debug/file_line_function.h"
#include "garnet/lib/debug_ipc/helper/zx_status.h"
#include "garnet/lib/debug_ipc/register_test_support.h"
diff --git a/garnet/bin/debug_agent/debug_agent.cc b/garnet/bin/debug_agent/debug_agent.cc
index d570884..6b6e701 100644
--- a/garnet/bin/debug_agent/debug_agent.cc
+++ b/garnet/bin/debug_agent/debug_agent.cc
@@ -20,6 +20,7 @@
#include "garnet/bin/debug_agent/process_info.h"
#include "garnet/bin/debug_agent/system_info.h"
#include "garnet/lib/debug_ipc/agent_protocol.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/lib/debug_ipc/helper/stream_buffer.h"
#include "garnet/lib/debug_ipc/message_reader.h"
#include "garnet/lib/debug_ipc/message_writer.h"
@@ -37,6 +38,7 @@
DebugAgent::~DebugAgent() = default;
void DebugAgent::OnProcessStart(zx::process process) {
+ TIME_BLOCK();
auto koid = KoidForObject(process);
auto name = NameForObject(process);
@@ -76,12 +78,14 @@
void DebugAgent::OnHello(const debug_ipc::HelloRequest& request,
debug_ipc::HelloReply* reply) {
+ TIME_BLOCK();
// Version and signature are default-initialized to their current values.
reply->arch = arch::ArchProvider::Get().GetArch();
}
void DebugAgent::OnLaunch(const debug_ipc::LaunchRequest& request,
debug_ipc::LaunchReply* reply) {
+ TIME_BLOCK();
switch (request.inferior_type) {
case debug_ipc::InferiorType::kBinary:
LaunchProcess(request, reply);
@@ -98,6 +102,7 @@
void DebugAgent::OnKill(const debug_ipc::KillRequest& request,
debug_ipc::KillReply* reply) {
+ TIME_BLOCK();
auto debug_process = GetDebuggedProcess(request.process_koid);
if (!debug_process || !debug_process->process().is_valid()) {
@@ -108,6 +113,7 @@
}
void DebugAgent::OnAttach(std::vector<char> serialized) {
+ TIME_BLOCK();
debug_ipc::MessageReader reader(std::move(serialized));
debug_ipc::AttachRequest request;
uint32_t transaction_id = 0;
@@ -203,6 +209,7 @@
void DebugAgent::OnDetach(const debug_ipc::DetachRequest& request,
debug_ipc::DetachReply* reply) {
+ TIME_BLOCK();
switch (request.type) {
case debug_ipc::DetachRequest::Type::kJob: {
auto debug_job = GetDebuggedJob(request.koid);
@@ -231,6 +238,7 @@
void DebugAgent::OnPause(const debug_ipc::PauseRequest& request,
debug_ipc::PauseReply* reply) {
+ TIME_BLOCK();
if (request.process_koid) {
// Single process.
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
@@ -245,12 +253,14 @@
void DebugAgent::OnQuitAgent(const debug_ipc::QuitAgentRequest& request,
debug_ipc::QuitAgentReply* reply) {
+ TIME_BLOCK();
should_quit_ = true;
debug_ipc::MessageLoop::Current()->QuitNow();
};
void DebugAgent::OnResume(const debug_ipc::ResumeRequest& request,
debug_ipc::ResumeReply* reply) {
+ TIME_BLOCK();
if (request.process_koid) {
// Single process.
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
@@ -265,6 +275,7 @@
void DebugAgent::OnModules(const debug_ipc::ModulesRequest& request,
debug_ipc::ModulesReply* reply) {
+ TIME_BLOCK();
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
if (proc)
proc->OnModules(reply);
@@ -272,11 +283,13 @@
void DebugAgent::OnProcessTree(const debug_ipc::ProcessTreeRequest& request,
debug_ipc::ProcessTreeReply* reply) {
+ TIME_BLOCK();
GetProcessTree(&reply->root);
}
void DebugAgent::OnThreads(const debug_ipc::ThreadsRequest& request,
debug_ipc::ThreadsReply* reply) {
+ TIME_BLOCK();
auto found = procs_.find(request.process_koid);
if (found == procs_.end())
return;
@@ -286,6 +299,7 @@
void DebugAgent::OnReadMemory(const debug_ipc::ReadMemoryRequest& request,
debug_ipc::ReadMemoryReply* reply) {
+ TIME_BLOCK();
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
if (proc)
proc->OnReadMemory(request, reply);
@@ -293,6 +307,7 @@
void DebugAgent::OnReadRegisters(const debug_ipc::ReadRegistersRequest& request,
debug_ipc::ReadRegistersReply* reply) {
+ TIME_BLOCK();
DebuggedThread* thread =
GetDebuggedThread(request.process_koid, request.thread_koid);
if (thread) {
@@ -305,6 +320,7 @@
void DebugAgent::OnWriteRegisters(
const debug_ipc::WriteRegistersRequest& request,
debug_ipc::WriteRegistersReply* reply) {
+ TIME_BLOCK();
DebuggedThread* thread =
GetDebuggedThread(request.process_koid, request.thread_koid);
if (thread) {
@@ -318,6 +334,7 @@
void DebugAgent::OnAddOrChangeBreakpoint(
const debug_ipc::AddOrChangeBreakpointRequest& request,
debug_ipc::AddOrChangeBreakpointReply* reply) {
+ TIME_BLOCK();
uint32_t id = request.breakpoint.breakpoint_id;
auto found = breakpoints_.find(id);
@@ -333,11 +350,13 @@
void DebugAgent::OnRemoveBreakpoint(
const debug_ipc::RemoveBreakpointRequest& request,
debug_ipc::RemoveBreakpointReply* reply) {
+ TIME_BLOCK();
RemoveBreakpoint(request.breakpoint_id);
}
void DebugAgent::OnThreadStatus(const debug_ipc::ThreadStatusRequest& request,
debug_ipc::ThreadStatusReply* reply) {
+ TIME_BLOCK();
DebuggedThread* thread =
GetDebuggedThread(request.process_koid, request.thread_koid);
if (thread) {
@@ -396,6 +415,7 @@
void DebugAgent::OnAddressSpace(const debug_ipc::AddressSpaceRequest& request,
debug_ipc::AddressSpaceReply* reply) {
+ TIME_BLOCK();
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
if (proc)
proc->OnAddressSpace(request, reply);
@@ -403,6 +423,7 @@
void DebugAgent::OnJobFilter(const debug_ipc::JobFilterRequest& request,
debug_ipc::JobFilterReply* reply) {
+ TIME_BLOCK();
DebuggedJob* job = GetDebuggedJob(request.job_koid);
if (!job) {
reply->status = ZX_ERR_INVALID_ARGS;
@@ -414,6 +435,7 @@
void DebugAgent::OnWriteMemory(const debug_ipc::WriteMemoryRequest& request,
debug_ipc::WriteMemoryReply* reply) {
+ TIME_BLOCK();
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
if (proc)
proc->OnWriteMemory(request, reply);
@@ -423,6 +445,7 @@
void DebugAgent::OnSymbolTables(const debug_ipc::SymbolTablesRequest& request,
debug_ipc::SymbolTablesReply* reply) {
+ TIME_BLOCK();
DebuggedProcess* proc = GetDebuggedProcess(request.process_koid);
if (proc)
proc->OnSymbolTables(request, reply);
diff --git a/garnet/bin/debug_agent/main.cc b/garnet/bin/debug_agent/main.cc
index cc33806..0f185ab 100644
--- a/garnet/bin/debug_agent/main.cc
+++ b/garnet/bin/debug_agent/main.cc
@@ -16,6 +16,7 @@
#include "garnet/bin/debug_agent/remote_api_adapter.h"
#include "garnet/bin/debug_agent/unwind.h"
#include "garnet/lib/debug_ipc/helper/buffered_fd.h"
+#include "garnet/lib/debug_ipc/debug/debug.h"
#include "garnet/lib/debug_ipc/helper/message_loop_async.h"
#include "garnet/lib/debug_ipc/helper/message_loop_target.h"
#include "garnet/lib/debug_ipc/helper/message_loop_zircon.h"
@@ -217,9 +218,10 @@
message_loop_type = MessageLoopTarget::LoopType::kAsync;
}
- bool debug_mode = false;
- if (cmdline.HasOption("debug-message-loop"))
- debug_mode = true;
+ if (cmdline.HasOption("debug-message-loop")) {
+ printf("Running message loop in debug mode.\n");
+ debug_ipc::SetDebugMode(true);
+ }
std::string value;
if (cmdline.GetOptionValue("port", &value)) {
@@ -238,11 +240,6 @@
auto message_loop = debug_agent::GetMessageLoop(message_loop_type);
message_loop->Init();
- if (debug_mode) {
- printf("Running message loop in debug mode.\n");
- message_loop->set_debug_mode(true);
- }
-
// The scope ensures the objects are destroyed before calling Cleanup on the
// MessageLoop.
{
diff --git a/garnet/bin/zxdb/client/process_impl.cc b/garnet/bin/zxdb/client/process_impl.cc
index ef0cb03..2ce3bb2 100644
--- a/garnet/bin/zxdb/client/process_impl.cc
+++ b/garnet/bin/zxdb/client/process_impl.cc
@@ -15,6 +15,7 @@
#include "garnet/bin/zxdb/client/thread_impl.h"
#include "garnet/bin/zxdb/symbols/input_location.h"
#include "garnet/bin/zxdb/symbols/loaded_module_symbols.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/public/lib/fxl/logging.h"
namespace zxdb {
@@ -164,6 +165,7 @@
}
void ProcessImpl::OnThreadStarting(const debug_ipc::ThreadRecord& record) {
+ TIME_BLOCK();
if (threads_.find(record.koid) != threads_.end()) {
// Duplicate new thread notification. Some legitimate cases could cause
// this, like the client requesting a thread list (which will add missing
@@ -180,6 +182,7 @@
}
void ProcessImpl::OnThreadExiting(const debug_ipc::ThreadRecord& record) {
+ TIME_BLOCK();
auto found = threads_.find(record.koid);
if (found == threads_.end()) {
// Duplicate exit thread notification. Some legitimate cases could cause
@@ -195,6 +198,7 @@
void ProcessImpl::OnModules(const std::vector<debug_ipc::Module>& modules,
const std::vector<uint64_t>& stopped_thread_koids) {
+ TIME_BLOCK();
symbols_.SetModules(modules);
// The threads loading the library will be stopped so we have time to load
@@ -270,6 +274,7 @@
}
void ProcessImpl::OnSymbolLoadFailure(const Err& err) {
+ TIME_BLOCK();
for (auto& observer : observers())
observer.OnSymbolLoadFailure(this, err);
}
diff --git a/garnet/bin/zxdb/client/session.cc b/garnet/bin/zxdb/client/session.cc
index 6ec619d..a2a1588 100644
--- a/garnet/bin/zxdb/client/session.cc
+++ b/garnet/bin/zxdb/client/session.cc
@@ -24,6 +24,7 @@
#include "garnet/bin/zxdb/client/thread_impl.h"
#include "garnet/lib/debug_ipc/client_protocol.h"
#include "garnet/lib/debug_ipc/helper/buffered_fd.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/lib/debug_ipc/helper/message_loop.h"
#include "garnet/lib/debug_ipc/helper/stream_buffer.h"
#include "garnet/lib/debug_ipc/message_reader.h"
@@ -530,6 +531,7 @@
void Session::DispatchNotifyException(
const debug_ipc::NotifyException& notify,
bool set_metadata) {
+ TIME_BLOCK();
ThreadImpl* thread =
ThreadImplFromKoid(notify.process_koid, notify.thread.koid);
if (!thread) {
diff --git a/garnet/bin/zxdb/client/target_impl.cc b/garnet/bin/zxdb/client/target_impl.cc
index 624f5cf..28d3b2f 100644
--- a/garnet/bin/zxdb/client/target_impl.cc
+++ b/garnet/bin/zxdb/client/target_impl.cc
@@ -11,6 +11,7 @@
#include "garnet/bin/zxdb/client/session.h"
#include "garnet/bin/zxdb/client/system_impl.h"
#include "garnet/bin/zxdb/client/target_observer.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/lib/debug_ipc/helper/message_loop.h"
#include "garnet/lib/debug_ipc/helper/zx_status.h"
#include "garnet/public/lib/fxl/logging.h"
@@ -41,6 +42,7 @@
void TargetImpl::ProcessCreatedInJob(uint64_t koid,
const std::string& process_name) {
+ TIME_BLOCK();
FXL_DCHECK(state_ == State::kNone);
FXL_DCHECK(!process_.get()); // Shouldn't have a process.
diff --git a/garnet/bin/zxdb/client/thread_impl.cc b/garnet/bin/zxdb/client/thread_impl.cc
index e235aaa..87b95a8 100644
--- a/garnet/bin/zxdb/client/thread_impl.cc
+++ b/garnet/bin/zxdb/client/thread_impl.cc
@@ -18,6 +18,7 @@
#include "garnet/bin/zxdb/client/target_impl.h"
#include "garnet/bin/zxdb/client/thread_controller.h"
#include "garnet/bin/zxdb/symbols/process_symbols.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/lib/debug_ipc/helper/message_loop.h"
#include "garnet/lib/debug_ipc/helper/zx_status.h"
#include "lib/fxl/logging.h"
@@ -241,6 +242,7 @@
void ThreadImpl::OnException(
debug_ipc::NotifyException::Type type,
const std::vector<fxl::WeakPtr<Breakpoint>>& hit_breakpoints) {
+ TIME_BLOCK();
#if defined(DEBUG_THREAD_CONTROLLERS)
ThreadController::LogRaw("----------\r\nGot exception @ 0x%" PRIx64,
stack_[0]->GetAddress());
diff --git a/garnet/bin/zxdb/console/console_main.cc b/garnet/bin/zxdb/console/console_main.cc
index 33c47fb..d84b4fe 100644
--- a/garnet/bin/zxdb/console/console_main.cc
+++ b/garnet/bin/zxdb/console/console_main.cc
@@ -14,6 +14,7 @@
#include "garnet/bin/zxdb/console/console.h"
#include "garnet/bin/zxdb/console/output_buffer.h"
#include "garnet/lib/debug_ipc/helper/buffered_fd.h"
+#include "garnet/lib/debug_ipc/debug/debug.h"
#include "garnet/lib/debug_ipc/helper/message_loop_poll.h"
#include "garnet/public/lib/fxl/command_line.h"
#include "garnet/public/lib/fxl/strings/string_printf.h"
@@ -92,7 +93,7 @@
debug_ipc::MessageLoopPoll loop;
if (options.debug_info)
- loop.set_debug_mode(true);
+ debug_ipc::SetDebugMode(true);
loop.Init();
diff --git a/garnet/lib/debug_ipc/debug/BUILD.gn b/garnet/lib/debug_ipc/debug/BUILD.gn
new file mode 100644
index 0000000..d38d530
--- /dev/null
+++ b/garnet/lib/debug_ipc/debug/BUILD.gn
@@ -0,0 +1,22 @@
+# Copyright 2019 The Fuchsia Authors. All rights reserved.
+# Use of this source code is governed by a BSD-style license that can be
+# found in the LICENSE file.
+
+# This library contains utilities useful to debug all clients of the zxdb suite.
+source_set("debug") {
+ public = [
+ "block_timer.h",
+ "file_line_function.h",
+ "debug.h",
+ ]
+
+ sources = [
+ "block_timer.cc",
+ "file_line_function.cc",
+ "debug.cc",
+ ]
+
+ deps = [
+ "//garnet/public/lib/fxl",
+ ]
+}
diff --git a/garnet/lib/debug_ipc/debug/block_timer.cc b/garnet/lib/debug_ipc/debug/block_timer.cc
new file mode 100644
index 0000000..afd04c5
--- /dev/null
+++ b/garnet/lib/debug_ipc/debug/block_timer.cc
@@ -0,0 +1,47 @@
+// Copyright 2019 The Fuchsia Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
+
+#include "garnet/lib/debug_ipc/debug/debug.h"
+
+namespace debug_ipc {
+
+BlockTimer::BlockTimer(FileLineFunction origin, const char* msg)
+ : origin_(origin), should_log_(IsDebugModeActive()), msg_(msg) {
+ if (should_log_)
+ timer_.Start();
+}
+
+BlockTimer::~BlockTimer() {
+ EndTimer();
+}
+
+void BlockTimer::EndTimer() {
+ if (should_log_) {
+ const char* unit = "ms";
+ double time = timer_.Elapsed().ToMillisecondsF();
+ // We see if seconds makes more sense.
+ if (time > 1000) {
+ time /= 1000;
+ // We write the full word to make more evident that this is 1000 times
+ // bigger that the normal numbers you normally see.
+ unit = "seconds";
+ }
+
+ if (!msg_) {
+ printf("\r[%.3fs]%s Took %.3f %s.\r\n", SecondsSinceStart(),
+ origin_.ToStringWithBasename().c_str(), time, unit);
+ } else {
+ printf("\r[%.3fs]%s[%s] Took %.3f %s.\r\n", SecondsSinceStart(),
+ origin_.ToStringWithBasename().c_str(), msg_, time, unit);
+ }
+ fflush(stdout);
+ }
+
+ // The timer won't trigger again.
+ should_log_ = false;
+}
+
+} // namespace debug_ipc
diff --git a/garnet/lib/debug_ipc/debug/block_timer.h b/garnet/lib/debug_ipc/debug/block_timer.h
new file mode 100644
index 0000000..18041dd
--- /dev/null
+++ b/garnet/lib/debug_ipc/debug/block_timer.h
@@ -0,0 +1,53 @@
+// Copyright 2019 The Fuchsia Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#pragma once
+
+#include "garnet/lib/debug_ipc/debug/file_line_function.h"
+#include "lib/fxl/macros.h"
+#include "lib/fxl/time/stopwatch.h"
+
+namespace debug_ipc {
+
+// BlockTimer ------------------------------------------------------------------
+
+// Simple RAII-esque timer that prints the duration of a block if running on
+// debug mode.
+//
+// Normally you would use it from the TIME_BLOCK macro (defined below), that
+// will easily add the current calling site, but you can add your own locations
+// in order to proxy calls (see message_loop.cc for an example).
+class BlockTimer {
+ public:
+ // If |msg| is not null, it will be added to the debug msg.
+ // The easier way is to used the TIME_BLOCK_MSG macro.
+ BlockTimer(FileLineFunction origin, const char* msg = nullptr);
+ ~BlockTimer(); // Will log on destruction.
+
+ // This is what get called on destruction. You can call it before destruction
+ // to trigger the timer before that. Will not trigger again.
+ void EndTimer();
+
+ // BlockTimers should only measure the block they're in. No weird stuff.
+ FXL_DISALLOW_COPY_AND_ASSIGN(BlockTimer);
+ FXL_DISALLOW_MOVE(BlockTimer);
+
+ private:
+ FileLineFunction origin_; // Where this timer was called from.
+ fxl::Stopwatch timer_;
+ bool should_log_;
+ const char* msg_;
+};
+
+// We use this macro to ensure the concatenation of the values. Oh macros :)
+#define TIME_BLOCK_TOKEN(x, y) x##y
+#define TIME_BLOCK_TOKEN2(x, y) TIME_BLOCK_TOKEN(x, y)
+
+#define TIME_BLOCK() \
+ ::debug_ipc::BlockTimer TIME_BLOCK_TOKEN2(block_timer_, __LINE__)(FROM_HERE)
+
+#define TIME_BLOCK_MSG(msg) \
+ ::debug_ipc::BlockTimer TIME_BLOCK_TOKEN2(block_timer_, __LINE__)(FROM_HERE, \
+ msg)
+} // namespace debug_ipc
diff --git a/garnet/lib/debug_ipc/debug/debug.cc b/garnet/lib/debug_ipc/debug/debug.cc
new file mode 100644
index 0000000..cc14a28
--- /dev/null
+++ b/garnet/lib/debug_ipc/debug/debug.cc
@@ -0,0 +1,32 @@
+// Copyright 2019 The Fuchsia Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "garnet/lib/debug_ipc/debug/debug.h"
+
+#include "lib/fxl/time/time_point.h"
+
+namespace debug_ipc {
+
+namespace {
+
+bool kDebugMode = false;
+
+// This marks the moment SetDebugMode was called.
+fxl::TimePoint kStartTime = fxl::TimePoint::Now();
+
+} // namespace
+
+bool IsDebugModeActive() {
+ return kDebugMode;
+}
+
+void SetDebugMode(bool activate) {
+ kDebugMode = activate;
+}
+
+double SecondsSinceStart() {
+ return (fxl::TimePoint::Now() - kStartTime).ToSecondsF();
+}
+
+} // namespace debug_ipc
diff --git a/garnet/lib/debug_ipc/debug/debug.h b/garnet/lib/debug_ipc/debug/debug.h
new file mode 100644
index 0000000..26a80d4
--- /dev/null
+++ b/garnet/lib/debug_ipc/debug/debug.h
@@ -0,0 +1,20 @@
+// Copyright 2019 The Fuchsia Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#pragma once
+
+namespace debug_ipc {
+
+// This API controls and queries the debug functionality of the debug tools
+// within the debug ipc.
+
+// Activate this flag to activate debug output.
+// False by default.
+void SetDebugMode(bool);
+bool IsDebugModeActive();
+
+// Returns how many seconds have passed since the program started.
+double SecondsSinceStart();
+
+} // namespace debug_ipc
diff --git a/garnet/lib/debug_ipc/helper/file_line_function.cc b/garnet/lib/debug_ipc/debug/file_line_function.cc
similarity index 66%
rename from garnet/lib/debug_ipc/helper/file_line_function.cc
rename to garnet/lib/debug_ipc/debug/file_line_function.cc
index f546064..bf75439 100644
--- a/garnet/lib/debug_ipc/helper/file_line_function.cc
+++ b/garnet/lib/debug_ipc/debug/file_line_function.cc
@@ -2,8 +2,9 @@
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
-#include "garnet/lib/debug_ipc/helper/file_line_function.h"
+#include "garnet/lib/debug_ipc/debug/file_line_function.h"
+#include "lib/fxl/files/path.h"
#include "lib/fxl/strings/string_printf.h"
namespace debug_ipc {
@@ -22,9 +23,19 @@
std::string FileLineFunction::ToString() const {
if (function_.empty()) {
- return fxl::StringPrintf("%s:%d", file_.data(), line_);
+ return fxl::StringPrintf("[%s:%d]", file_.data(), line_);
} else {
- return fxl::StringPrintf("%s:%d (%s)", file_.data(), line_,
+ return fxl::StringPrintf("[%s:%d][%s]", file_.data(), line_,
+ function_.data());
+ }
+}
+
+std::string FileLineFunction::ToStringWithBasename() const {
+ auto basename = files::GetBaseName(file_.c_str());
+ if (function_.empty()) {
+ return fxl::StringPrintf("[%s:%d]", basename.c_str(), line_);
+ } else {
+ return fxl::StringPrintf("[%s:%d][%s]", basename.data(), line_,
function_.data());
}
}
diff --git a/garnet/lib/debug_ipc/helper/file_line_function.h b/garnet/lib/debug_ipc/debug/file_line_function.h
similarity index 85%
rename from garnet/lib/debug_ipc/helper/file_line_function.h
rename to garnet/lib/debug_ipc/debug/file_line_function.h
index a41fc48..0504890 100644
--- a/garnet/lib/debug_ipc/helper/file_line_function.h
+++ b/garnet/lib/debug_ipc/debug/file_line_function.h
@@ -9,7 +9,7 @@
namespace debug_ipc {
#define FROM_HERE \
- ::debug_ipc::FileLineFunction(__FILE__, __LINE__, __PRETTY_FUNCTION__)
+ ::debug_ipc::FileLineFunction(__FILE__, __LINE__, __FUNCTION__)
#define FROM_HERE_NO_FUNC ::debug_ipc::FileLineFunction(__FILE__, __LINE__)
class FileLineFunction {
@@ -24,6 +24,8 @@
int line() const { return line_; }
std::string ToString() const;
+ // Removes everything up the the filename from the file path.
+ std::string ToStringWithBasename() const;
private:
std::string file_;
diff --git a/garnet/lib/debug_ipc/helper/BUILD.gn b/garnet/lib/debug_ipc/helper/BUILD.gn
index 435916f..d6564a6 100644
--- a/garnet/lib/debug_ipc/helper/BUILD.gn
+++ b/garnet/lib/debug_ipc/helper/BUILD.gn
@@ -12,8 +12,6 @@
"buffered_fd.h",
"elf.cc",
"elf.h",
- "file_line_function.cc",
- "file_line_function.h",
"message_loop.cc",
"message_loop.h",
"regex.cc",
@@ -28,7 +26,7 @@
]
public_deps = [
- #"//garnet/public/lib/component/cpp",
+ "//garnet/lib/debug_ipc/debug",
"//garnet/public/lib/fxl",
]
diff --git a/garnet/lib/debug_ipc/helper/event_handlers.cc b/garnet/lib/debug_ipc/helper/event_handlers.cc
index 1bab6f7f..c7395fa 100644
--- a/garnet/lib/debug_ipc/helper/event_handlers.cc
+++ b/garnet/lib/debug_ipc/helper/event_handlers.cc
@@ -31,8 +31,8 @@
if (handle_) {
async_wait_t* wait = handle_.get();
- zx_status_t res = async_cancel_wait(async_get_default_dispatcher(), wait);
- FXL_DCHECK(res == ZX_OK);
+ auto status = async_cancel_wait(async_get_default_dispatcher(), wait);
+ FXL_DCHECK(status == ZX_OK) << "Got: " << ZxStatusToString(status);
}
}
diff --git a/garnet/lib/debug_ipc/helper/message_loop.cc b/garnet/lib/debug_ipc/helper/message_loop.cc
index fe03304..4a98d8b 100644
--- a/garnet/lib/debug_ipc/helper/message_loop.cc
+++ b/garnet/lib/debug_ipc/helper/message_loop.cc
@@ -4,6 +4,7 @@
#include "garnet/lib/debug_ipc/helper/message_loop.h"
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/public/lib/fxl/logging.h"
namespace debug_ipc {
@@ -61,11 +62,10 @@
task_queue_.pop_front();
{
mutex_.unlock();
- if (debug_mode()) {
- FXL_LOG(INFO) << "Running task from [" << task.file_line.ToString()
- << "]";
+ {
+ debug_ipc::BlockTimer(task.file_line);
+ task.task_fn();
}
- task.task_fn();
mutex_.lock();
}
return true;
diff --git a/garnet/lib/debug_ipc/helper/message_loop.h b/garnet/lib/debug_ipc/helper/message_loop.h
index 4c0d4d3..cb960ff 100644
--- a/garnet/lib/debug_ipc/helper/message_loop.h
+++ b/garnet/lib/debug_ipc/helper/message_loop.h
@@ -9,7 +9,7 @@
#include <map>
#include <mutex>
-#include "garnet/lib/debug_ipc/helper/file_line_function.h"
+#include "garnet/lib/debug_ipc/debug/file_line_function.h"
#include "lib/fxl/macros.h"
#if defined(__Fuchsia__)
@@ -72,9 +72,6 @@
// the same underlying OS handle, so the caller can only watch one of them.
virtual WatchHandle WatchFD(WatchMode mode, int fd, FDWatcher* watcher) = 0;
- bool debug_mode() const { return debug_mode_; }
- void set_debug_mode(bool active) { debug_mode_ = active; }
-
protected:
virtual void RunImpl() = 0;
@@ -112,9 +109,6 @@
bool should_quit_ = false;
- // Whether the message loop should output debug information.
- bool debug_mode_ = false;
-
FXL_DISALLOW_COPY_AND_ASSIGN(MessageLoop);
};
diff --git a/garnet/lib/debug_ipc/helper/message_loop_async.cc b/garnet/lib/debug_ipc/helper/message_loop_async.cc
index 20fdd56..ffe3afd 100644
--- a/garnet/lib/debug_ipc/helper/message_loop_async.cc
+++ b/garnet/lib/debug_ipc/helper/message_loop_async.cc
@@ -4,12 +4,15 @@
#include "garnet/lib/debug_ipc/helper/message_loop_async.h"
+#include <stdio.h>
+
#include <lib/fdio/io.h>
#include <lib/zx/handle.h>
#include <lib/zx/job.h>
#include <lib/zx/process.h>
#include <zircon/syscalls/exception.h>
+#include "garnet/lib/debug_ipc/debug/block_timer.h"
#include "garnet/lib/debug_ipc/helper/event_handlers.h"
#include "garnet/lib/debug_ipc/helper/fd_watcher.h"
#include "garnet/lib/debug_ipc/helper/socket_watcher.h"
@@ -391,6 +394,8 @@
void MessageLoopAsync::OnFdioSignal(int watch_id, const WatchInfo& info,
zx_signals_t observed) {
+ TIME_BLOCK();
+
uint32_t events = 0;
fdio_unsafe_wait_end(info.fdio, observed, &events);
@@ -451,6 +456,8 @@
void MessageLoopAsync::OnProcessException(const ExceptionHandler& handler,
const WatchInfo& info,
const zx_port_packet_t& packet) {
+ TIME_BLOCK();
+
if (ZX_PKT_IS_EXCEPTION(packet.type)) {
// All debug exceptions.
switch (packet.type) {
@@ -492,6 +499,8 @@
void MessageLoopAsync::OnJobException(const ExceptionHandler& handler,
const WatchInfo& info,
const zx_port_packet_t& packet) {
+ TIME_BLOCK();
+
if (ZX_PKT_IS_EXCEPTION(packet.type)) {
// All debug exceptions.
switch (packet.type) {
@@ -509,6 +518,8 @@
void MessageLoopAsync::OnSocketSignal(int watch_id, const WatchInfo& info,
zx_signals_t observed) {
+ TIME_BLOCK();
+
FXL_LOG(INFO) << __FUNCTION__;
// Dispatch readable signal.
if (observed & ZX_SOCKET_READABLE)
