Commit 6f0c3820 authored by Mike Wittman's avatar Mike Wittman Committed by Commit Bot

[Sampling profiler] Provide timestamp with sample

Records timestamps along with samples and plumbs them through to
the ProfileBuilder interface. The CallStackProfileBuilder subclass
will be updated in a following CL to record the timestamps, to
support retrospective tagging of metadata on the samples.

Bug: 1034758
Change-Id: Ic631d47773db5ce8ed5117c08aba5d5931cb7884
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1972931Reviewed-by: default avatarLei Zhang <thestig@chromium.org>
Reviewed-by: default avatarEtienne Pierre-Doray <etiennep@chromium.org>
Reviewed-by: default avataroysteine <oysteine@chromium.org>
Commit-Queue: Mike Wittman <wittman@chromium.org>
Cr-Commit-Position: refs/heads/master@{#726526}
parent f66cac50
...@@ -62,7 +62,8 @@ class BASE_EXPORT ProfileBuilder { ...@@ -62,7 +62,8 @@ class BASE_EXPORT ProfileBuilder {
virtual void RecordMetadata(MetadataProvider* metadata_provider) {} virtual void RecordMetadata(MetadataProvider* metadata_provider) {}
// Records a new set of frames. Invoked when sampling a sample completes. // Records a new set of frames. Invoked when sampling a sample completes.
virtual void OnSampleCompleted(std::vector<Frame> frames) = 0; virtual void OnSampleCompleted(std::vector<Frame> frames,
TimeTicks sample_timestamp) = 0;
// Finishes the profile construction with |profile_duration| and // Finishes the profile construction with |profile_duration| and
// |sampling_period|. Invoked when sampling a profile completes. // |sampling_period|. Invoked when sampling a profile completes.
......
...@@ -9,6 +9,7 @@ ...@@ -9,6 +9,7 @@
#include "base/base_export.h" #include "base/base_export.h"
#include "base/profiler/register_context.h" #include "base/profiler/register_context.h"
#include "base/time/time.h"
namespace base { namespace base {
...@@ -26,11 +27,12 @@ class BASE_EXPORT StackCopier { ...@@ -26,11 +27,12 @@ class BASE_EXPORT StackCopier {
// Copies the thread's register context into |thread_context|, the stack into // Copies the thread's register context into |thread_context|, the stack into
// |stack_buffer|, and the top of stack address into |stack_top|. Records // |stack_buffer|, and the top of stack address into |stack_top|. Records
// metadata while the thread is suspended via |profile_builder|. Returns true // metadata while the thread is suspended via |profile_builder|. Records
// if successful. // |timestamp| at the time the stack was copied. Returns true if successful.
virtual bool CopyStack(StackBuffer* stack_buffer, virtual bool CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) = 0; RegisterContext* thread_context) = 0;
protected: protected:
......
...@@ -82,13 +82,19 @@ struct HandlerParams { ...@@ -82,13 +82,19 @@ struct HandlerParams {
AsyncSafeWaitableEvent* event; AsyncSafeWaitableEvent* event;
// Return values: // Return values:
// Successfully copied the stack segment. // Successfully copied the stack segment.
bool* success; bool* success;
// The thread context of the leaf function. // The thread context of the leaf function.
mcontext_t* context; mcontext_t* context;
// Buffer to copy the stack segment. // Buffer to copy the stack segment.
StackBuffer* stack_buffer; StackBuffer* stack_buffer;
const uint8_t** stack_copy_bottom; const uint8_t** stack_copy_bottom;
// The timestamp when the stack was copied.
TimeTicks* timestamp;
}; };
// Pointer to the parameters to be "passed" to the CopyStackSignalHandler() from // Pointer to the parameters to be "passed" to the CopyStackSignalHandler() from
...@@ -101,6 +107,11 @@ std::atomic<HandlerParams*> g_handler_params; ...@@ -101,6 +107,11 @@ std::atomic<HandlerParams*> g_handler_params;
// function may only call reentrant code. // function may only call reentrant code.
void CopyStackSignalHandler(int n, siginfo_t* siginfo, void* sigcontext) { void CopyStackSignalHandler(int n, siginfo_t* siginfo, void* sigcontext) {
HandlerParams* params = g_handler_params.load(std::memory_order_acquire); HandlerParams* params = g_handler_params.load(std::memory_order_acquire);
// TimeTicks::Now() is implemented in terms of clock_gettime on Linux, which
// is signal safe per the signal-safety(7) man page.
*params->timestamp = TimeTicks::Now();
ScopedEventSignaller e(params->event); ScopedEventSignaller e(params->event);
*params->success = false; *params->success = false;
...@@ -176,13 +187,15 @@ StackCopierSignal::~StackCopierSignal() = default; ...@@ -176,13 +187,15 @@ StackCopierSignal::~StackCopierSignal() = default;
bool StackCopierSignal::CopyStack(StackBuffer* stack_buffer, bool StackCopierSignal::CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) { RegisterContext* thread_context) {
AsyncSafeWaitableEvent wait_event; AsyncSafeWaitableEvent wait_event;
bool copied = false; bool copied = false;
const uint8_t* stack_copy_bottom = nullptr; const uint8_t* stack_copy_bottom = nullptr;
const uintptr_t stack_base_address = thread_delegate_->GetStackBaseAddress(); const uintptr_t stack_base_address = thread_delegate_->GetStackBaseAddress();
HandlerParams params = {stack_base_address, &wait_event, &copied, HandlerParams params = {stack_base_address, &wait_event, &copied,
thread_context, stack_buffer, &stack_copy_bottom}; thread_context, stack_buffer, &stack_copy_bottom,
timestamp};
{ {
ScopedSetSignalHandlerParams scoped_handler_params(&params); ScopedSetSignalHandlerParams scoped_handler_params(&params);
......
...@@ -25,6 +25,7 @@ class BASE_EXPORT StackCopierSignal : public StackCopier { ...@@ -25,6 +25,7 @@ class BASE_EXPORT StackCopierSignal : public StackCopier {
bool CopyStack(StackBuffer* stack_buffer, bool CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) override; RegisterContext* thread_context) override;
using StackCopier::CopyStackContentsAndRewritePointers; using StackCopier::CopyStackContentsAndRewritePointers;
......
...@@ -35,7 +35,8 @@ class TestProfileBuilder : public ProfileBuilder { ...@@ -35,7 +35,8 @@ class TestProfileBuilder : public ProfileBuilder {
void RecordMetadata( void RecordMetadata(
base::ProfileBuilder::MetadataProvider* metadata_provider) override {} base::ProfileBuilder::MetadataProvider* metadata_provider) override {}
void OnSampleCompleted(std::vector<Frame> frames) override {} void OnSampleCompleted(std::vector<Frame> frames,
TimeTicks sample_timestamp) override {}
void OnProfileCompleted(TimeDelta profile_duration, void OnProfileCompleted(TimeDelta profile_duration,
TimeDelta sampling_period) override {} TimeDelta sampling_period) override {}
...@@ -95,6 +96,7 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) { ...@@ -95,6 +96,7 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) {
memset(stack_buffer.buffer(), 0, stack_buffer.size()); memset(stack_buffer.buffer(), 0, stack_buffer.size());
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TestProfileBuilder profiler_builder; TestProfileBuilder profiler_builder;
TimeTicks timestamp;
RegisterContext context; RegisterContext context;
StackCopierSignal copier(std::make_unique<ThreadDelegatePosix>( StackCopierSignal copier(std::make_unique<ThreadDelegatePosix>(
...@@ -106,8 +108,8 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) { ...@@ -106,8 +108,8 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) {
for (size_t i = 0; i < size(kStackSentinels); ++i) for (size_t i = 0; i < size(kStackSentinels); ++i)
sentinels[i] = kStackSentinels[i]; sentinels[i] = kStackSentinels[i];
bool result = bool result = copier.CopyStack(&stack_buffer, &stack_top, &profiler_builder,
copier.CopyStack(&stack_buffer, &stack_top, &profiler_builder, &context); &timestamp, &context);
ASSERT_TRUE(result); ASSERT_TRUE(result);
uint32_t* const end = reinterpret_cast<uint32_t*>(stack_top); uint32_t* const end = reinterpret_cast<uint32_t*>(stack_top);
...@@ -120,6 +122,33 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) { ...@@ -120,6 +122,33 @@ TEST(StackCopierSignalTest, MAYBE_CopyStack) {
EXPECT_NE(end, sentinel_location); EXPECT_NE(end, sentinel_location);
} }
// TSAN hangs on the AsyncSafeWaitableEvent FUTEX_WAIT call.
#if defined(THREAD_SANITIZER)
#define MAYBE_CopyStackTimestamp DISABLED_CopyStackTimestamp
#else
#define MAYBE_CopyStackTimestamp CopyStackTimestamp
#endif
TEST(StackCopierSignalTest, MAYBE_CopyStackTimestamp) {
StackBuffer stack_buffer(/* buffer_size = */ 1 << 20);
memset(stack_buffer.buffer(), 0, stack_buffer.size());
uintptr_t stack_top = 0;
TestProfileBuilder profiler_builder;
TimeTicks timestamp;
RegisterContext context;
StackCopierSignal copier(std::make_unique<ThreadDelegatePosix>(
GetSamplingProfilerCurrentThreadToken()));
TimeTicks before = TimeTicks::Now();
bool result = copier.CopyStack(&stack_buffer, &stack_top, &profiler_builder,
&timestamp, &context);
TimeTicks after = TimeTicks::Now();
ASSERT_TRUE(result);
EXPECT_GE(timestamp, before);
EXPECT_LE(timestamp, after);
}
// Limit to 32-bit Android, which is the platform we care about for this // Limit to 32-bit Android, which is the platform we care about for this
// functionality. The test is broken on too many other varied platforms to try // functionality. The test is broken on too many other varied platforms to try
// to selectively disable. // to selectively disable.
...@@ -133,6 +162,7 @@ TEST(StackCopierSignalTest, MAYBE_CopyStackFromOtherThread) { ...@@ -133,6 +162,7 @@ TEST(StackCopierSignalTest, MAYBE_CopyStackFromOtherThread) {
memset(stack_buffer.buffer(), 0, stack_buffer.size()); memset(stack_buffer.buffer(), 0, stack_buffer.size());
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TestProfileBuilder profiler_builder; TestProfileBuilder profiler_builder;
TimeTicks timestamp;
RegisterContext context{}; RegisterContext context{};
TargetThread target_thread; TargetThread target_thread;
...@@ -142,8 +172,8 @@ TEST(StackCopierSignalTest, MAYBE_CopyStackFromOtherThread) { ...@@ -142,8 +172,8 @@ TEST(StackCopierSignalTest, MAYBE_CopyStackFromOtherThread) {
StackCopierSignal copier(std::make_unique<ThreadDelegatePosix>(thread_token)); StackCopierSignal copier(std::make_unique<ThreadDelegatePosix>(thread_token));
bool result = bool result = copier.CopyStack(&stack_buffer, &stack_top, &profiler_builder,
copier.CopyStack(&stack_buffer, &stack_top, &profiler_builder, &context); &timestamp, &context);
ASSERT_TRUE(result); ASSERT_TRUE(result);
target_thread.NotifyCopyFinished(); target_thread.NotifyCopyFinished();
......
...@@ -26,6 +26,7 @@ StackCopierSuspend::~StackCopierSuspend() = default; ...@@ -26,6 +26,7 @@ StackCopierSuspend::~StackCopierSuspend() = default;
bool StackCopierSuspend::CopyStack(StackBuffer* stack_buffer, bool StackCopierSuspend::CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) { RegisterContext* thread_context) {
const uintptr_t top = thread_delegate_->GetStackBaseAddress(); const uintptr_t top = thread_delegate_->GetStackBaseAddress();
uintptr_t bottom = 0; uintptr_t bottom = 0;
...@@ -42,6 +43,10 @@ bool StackCopierSuspend::CopyStack(StackBuffer* stack_buffer, ...@@ -42,6 +43,10 @@ bool StackCopierSuspend::CopyStack(StackBuffer* stack_buffer,
std::unique_ptr<SuspendableThreadDelegate::ScopedSuspendThread> std::unique_ptr<SuspendableThreadDelegate::ScopedSuspendThread>
suspend_thread = thread_delegate_->CreateScopedSuspendThread(); suspend_thread = thread_delegate_->CreateScopedSuspendThread();
// TimeTicks::Now() is implemented in terms of reads to the timer tick
// counter or TSC register on x86/x86_64 so is reentrant.
*timestamp = TimeTicks::Now();
if (!suspend_thread->WasSuccessful()) if (!suspend_thread->WasSuccessful())
return false; return false;
......
...@@ -27,6 +27,7 @@ class BASE_EXPORT StackCopierSuspend : public StackCopier { ...@@ -27,6 +27,7 @@ class BASE_EXPORT StackCopierSuspend : public StackCopier {
bool CopyStack(StackBuffer* stack_buffer, bool CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) override; RegisterContext* thread_context) override;
private: private:
......
...@@ -98,7 +98,8 @@ class TestProfileBuilder : public ProfileBuilder { ...@@ -98,7 +98,8 @@ class TestProfileBuilder : public ProfileBuilder {
recorded_metadata_ = true; recorded_metadata_ = true;
} }
void OnSampleCompleted(std::vector<Frame> frames) override {} void OnSampleCompleted(std::vector<Frame> frames,
TimeTicks sample_timestamp) override {}
void OnProfileCompleted(TimeDelta profile_duration, void OnProfileCompleted(TimeDelta profile_duration,
TimeDelta sampling_period) override {} TimeDelta sampling_period) override {}
...@@ -117,9 +118,11 @@ TEST(StackCopierSuspendTest, CopyStack) { ...@@ -117,9 +118,11 @@ TEST(StackCopierSuspendTest, CopyStack) {
std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t)); std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t));
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TestProfileBuilder profile_builder; TestProfileBuilder profile_builder;
TimeTicks timestamp;
RegisterContext register_context{}; RegisterContext register_context{};
stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top, stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top,
&profile_builder, &register_context); &profile_builder, &timestamp,
&register_context);
uintptr_t* stack_copy_bottom = uintptr_t* stack_copy_bottom =
reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer()); reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer());
...@@ -139,9 +142,11 @@ TEST(StackCopierSuspendTest, CopyStackBufferTooSmall) { ...@@ -139,9 +142,11 @@ TEST(StackCopierSuspendTest, CopyStackBufferTooSmall) {
stack_buffer->buffer()[0] = 100; stack_buffer->buffer()[0] = 100;
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TestProfileBuilder profile_builder; TestProfileBuilder profile_builder;
TimeTicks timestamp;
RegisterContext register_context{}; RegisterContext register_context{};
stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top, stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top,
&profile_builder, &register_context); &profile_builder, &timestamp,
&register_context);
uintptr_t* stack_copy_bottom = uintptr_t* stack_copy_bottom =
reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer()); reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer());
...@@ -164,9 +169,11 @@ TEST(StackCopierSuspendTest, CopyStackAndRewritePointers) { ...@@ -164,9 +169,11 @@ TEST(StackCopierSuspendTest, CopyStackAndRewritePointers) {
std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t)); std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t));
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TestProfileBuilder profile_builder; TestProfileBuilder profile_builder;
TimeTicks timestamp;
RegisterContext register_context{}; RegisterContext register_context{};
stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top, stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top,
&profile_builder, &register_context); &profile_builder, &timestamp,
&register_context);
uintptr_t* stack_copy_bottom = uintptr_t* stack_copy_bottom =
reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer()); reinterpret_cast<uintptr_t*>(stack_buffer.get()->buffer());
...@@ -178,6 +185,28 @@ TEST(StackCopierSuspendTest, CopyStackAndRewritePointers) { ...@@ -178,6 +185,28 @@ TEST(StackCopierSuspendTest, CopyStackAndRewritePointers) {
sizeof(uintptr_t))); sizeof(uintptr_t)));
} }
TEST(StackCopierSuspendTest, CopyStackTimeStamp) {
const std::vector<uintptr_t> stack = {0};
StackCopierSuspend stack_copier_suspend(
std::make_unique<TestSuspendableThreadDelegate>(stack));
std::unique_ptr<StackBuffer> stack_buffer =
std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t));
uintptr_t stack_top = 0;
TestProfileBuilder profile_builder;
TimeTicks timestamp;
RegisterContext register_context{};
TimeTicks before = TimeTicks::Now();
stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top,
&profile_builder, &timestamp,
&register_context);
TimeTicks after = TimeTicks::Now();
EXPECT_GE(timestamp, before);
EXPECT_LE(timestamp, after);
}
TEST(StackCopierSuspendTest, RewriteRegisters) { TEST(StackCopierSuspendTest, RewriteRegisters) {
std::vector<uintptr_t> stack = {0, 1, 2}; std::vector<uintptr_t> stack = {0, 1, 2};
RegisterContext register_context{}; RegisterContext register_context{};
...@@ -190,9 +219,11 @@ TEST(StackCopierSuspendTest, RewriteRegisters) { ...@@ -190,9 +219,11 @@ TEST(StackCopierSuspendTest, RewriteRegisters) {
std::unique_ptr<StackBuffer> stack_buffer = std::unique_ptr<StackBuffer> stack_buffer =
std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t)); std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t));
uintptr_t stack_top = 0; uintptr_t stack_top = 0;
TimeTicks timestamp;
TestProfileBuilder profile_builder; TestProfileBuilder profile_builder;
stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top, stack_copier_suspend.CopyStack(stack_buffer.get(), &stack_top,
&profile_builder, &register_context); &profile_builder, &timestamp,
&register_context);
uintptr_t stack_copy_bottom = uintptr_t stack_copy_bottom =
reinterpret_cast<uintptr_t>(stack_buffer.get()->buffer()); reinterpret_cast<uintptr_t>(stack_buffer.get()->buffer());
......
...@@ -45,8 +45,9 @@ void StackSamplerImpl::RecordStackFrames(StackBuffer* stack_buffer, ...@@ -45,8 +45,9 @@ void StackSamplerImpl::RecordStackFrames(StackBuffer* stack_buffer,
RegisterContext thread_context; RegisterContext thread_context;
uintptr_t stack_top; uintptr_t stack_top;
bool success = stack_copier_->CopyStack(stack_buffer, &stack_top, TimeTicks timestamp;
profile_builder, &thread_context); bool success = stack_copier_->CopyStack(
stack_buffer, &stack_top, profile_builder, &timestamp, &thread_context);
if (!success) if (!success)
return; return;
...@@ -55,7 +56,8 @@ void StackSamplerImpl::RecordStackFrames(StackBuffer* stack_buffer, ...@@ -55,7 +56,8 @@ void StackSamplerImpl::RecordStackFrames(StackBuffer* stack_buffer,
profile_builder->OnSampleCompleted( profile_builder->OnSampleCompleted(
WalkStack(module_cache_, &thread_context, stack_top, WalkStack(module_cache_, &thread_context, stack_top,
native_unwinder_.get(), aux_unwinder_.get())); native_unwinder_.get(), aux_unwinder_.get()),
timestamp);
} }
// static // static
......
...@@ -37,24 +37,34 @@ class TestProfileBuilder : public ProfileBuilder { ...@@ -37,24 +37,34 @@ class TestProfileBuilder : public ProfileBuilder {
ModuleCache* GetModuleCache() override { return module_cache_; } ModuleCache* GetModuleCache() override { return module_cache_; }
void RecordMetadata( void RecordMetadata(
ProfileBuilder::MetadataProvider* metadata_provider) override {} ProfileBuilder::MetadataProvider* metadata_provider) override {}
void OnSampleCompleted(std::vector<Frame> frames) override {}
void OnSampleCompleted(std::vector<Frame> frames,
TimeTicks sample_timestamp) override {
last_timestamp_ = sample_timestamp;
}
void OnProfileCompleted(TimeDelta profile_duration, void OnProfileCompleted(TimeDelta profile_duration,
TimeDelta sampling_period) override {} TimeDelta sampling_period) override {}
TimeTicks last_timestamp() { return last_timestamp_; }
private: private:
ModuleCache* module_cache_; ModuleCache* module_cache_;
TimeTicks last_timestamp_;
}; };
// A stack copier for use in tests that provides the expected behavior when // A stack copier for use in tests that provides the expected behavior when
// operating on the supplied fake stack. // operating on the supplied fake stack.
class TestStackCopier : public StackCopier { class TestStackCopier : public StackCopier {
public: public:
TestStackCopier(const std::vector<uintptr_t>& fake_stack) TestStackCopier(const std::vector<uintptr_t>& fake_stack,
: fake_stack_(fake_stack) {} TimeTicks timestamp = TimeTicks())
: fake_stack_(fake_stack), timestamp_(timestamp) {}
bool CopyStack(StackBuffer* stack_buffer, bool CopyStack(StackBuffer* stack_buffer,
uintptr_t* stack_top, uintptr_t* stack_top,
ProfileBuilder* profile_builder, ProfileBuilder* profile_builder,
TimeTicks* timestamp,
RegisterContext* thread_context) override { RegisterContext* thread_context) override {
std::memcpy(stack_buffer->buffer(), &fake_stack_[0], fake_stack_.size()); std::memcpy(stack_buffer->buffer(), &fake_stack_[0], fake_stack_.size());
*stack_top = *stack_top =
...@@ -63,6 +73,8 @@ class TestStackCopier : public StackCopier { ...@@ -63,6 +73,8 @@ class TestStackCopier : public StackCopier {
RegisterContextStackPointer(thread_context) = RegisterContextStackPointer(thread_context) =
reinterpret_cast<uintptr_t>(&fake_stack_[0]); reinterpret_cast<uintptr_t>(&fake_stack_[0]);
*timestamp = timestamp_;
return true; return true;
} }
...@@ -70,6 +82,8 @@ class TestStackCopier : public StackCopier { ...@@ -70,6 +82,8 @@ class TestStackCopier : public StackCopier {
// Must be a reference to retain the underlying allocation from the vector // Must be a reference to retain the underlying allocation from the vector
// passed to the constructor. // passed to the constructor.
const std::vector<uintptr_t>& fake_stack_; const std::vector<uintptr_t>& fake_stack_;
const TimeTicks timestamp_;
}; };
// Trivial unwinder implementation for testing. // Trivial unwinder implementation for testing.
...@@ -225,6 +239,24 @@ TEST(StackSamplerImplTest, MAYBE_CopyStack) { ...@@ -225,6 +239,24 @@ TEST(StackSamplerImplTest, MAYBE_CopyStack) {
EXPECT_EQ(stack, stack_copy); EXPECT_EQ(stack, stack_copy);
} }
TEST(StackSamplerImplTest, CopyStackTimestamp) {
ModuleCache module_cache;
const std::vector<uintptr_t> stack = {0};
InjectModuleForContextInstructionPointer(stack, &module_cache);
std::vector<uintptr_t> stack_copy;
TimeTicks timestamp = TimeTicks::UnixEpoch();
StackSamplerImpl stack_sampler_impl(
std::make_unique<TestStackCopier>(stack, timestamp),
std::make_unique<TestUnwinder>(stack.size(), &stack_copy), &module_cache);
std::unique_ptr<StackBuffer> stack_buffer =
std::make_unique<StackBuffer>(stack.size() * sizeof(uintptr_t));
TestProfileBuilder profile_builder(&module_cache);
stack_sampler_impl.RecordStackFrames(stack_buffer.get(), &profile_builder);
EXPECT_EQ(timestamp, profile_builder.last_timestamp());
}
TEST(StackSamplerImplTest, WalkStack_Completed) { TEST(StackSamplerImplTest, WalkStack_Completed) {
ModuleCache module_cache; ModuleCache module_cache;
RegisterContext thread_context; RegisterContext thread_context;
......
...@@ -37,7 +37,8 @@ class TestProfileBuilder : public ProfileBuilder { ...@@ -37,7 +37,8 @@ class TestProfileBuilder : public ProfileBuilder {
ModuleCache* GetModuleCache() override { return module_cache_; } ModuleCache* GetModuleCache() override { return module_cache_; }
void RecordMetadata(MetadataProvider* metadata_provider) override {} void RecordMetadata(MetadataProvider* metadata_provider) override {}
void OnSampleCompleted(std::vector<Frame> sample) override { void OnSampleCompleted(std::vector<Frame> sample,
TimeTicks sample_timestamp) override {
EXPECT_TRUE(sample_.empty()); EXPECT_TRUE(sample_.empty());
sample_ = std::move(sample); sample_ = std::move(sample);
} }
......
...@@ -174,7 +174,8 @@ class TestProfileBuilder : public ProfileBuilder { ...@@ -174,7 +174,8 @@ class TestProfileBuilder : public ProfileBuilder {
ModuleCache* GetModuleCache() override; ModuleCache* GetModuleCache() override;
void RecordMetadata( void RecordMetadata(
ProfileBuilder::MetadataProvider* metadata_provider) override; ProfileBuilder::MetadataProvider* metadata_provider) override;
void OnSampleCompleted(std::vector<Frame> sample) override; void OnSampleCompleted(std::vector<Frame> sample,
TimeTicks sample_timestamp) override;
void OnProfileCompleted(TimeDelta profile_duration, void OnProfileCompleted(TimeDelta profile_duration,
TimeDelta sampling_period) override; TimeDelta sampling_period) override;
...@@ -208,7 +209,8 @@ void TestProfileBuilder::RecordMetadata( ...@@ -208,7 +209,8 @@ void TestProfileBuilder::RecordMetadata(
++metadata_count_; ++metadata_count_;
} }
void TestProfileBuilder::OnSampleCompleted(std::vector<Frame> sample) { void TestProfileBuilder::OnSampleCompleted(std::vector<Frame> sample,
TimeTicks sample_timestamp) {
samples_.push_back(std::move(sample)); samples_.push_back(std::move(sample));
} }
......
...@@ -107,7 +107,10 @@ void HeapProfilerController::RetrieveAndSendSnapshot() { ...@@ -107,7 +107,10 @@ void HeapProfilerController::RetrieveAndSendSnapshot() {
static_cast<size_t>( static_cast<size_t>(
std::llround(static_cast<double>(sample.total) / sample.size)), std::llround(static_cast<double>(sample.total) / sample.size)),
1); 1);
profile_builder.OnSampleCompleted(std::move(frames), sample.total, count); // Heap "samples" represent allocation stacks aggregated over time so do not
// have a meaningful timestamp.
profile_builder.OnSampleCompleted(std::move(frames), base::TimeTicks(),
sample.total, count);
} }
profile_builder.OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder.OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
......
...@@ -87,13 +87,16 @@ void CallStackProfileBuilder::RecordMetadata( ...@@ -87,13 +87,16 @@ void CallStackProfileBuilder::RecordMetadata(
} }
void CallStackProfileBuilder::OnSampleCompleted( void CallStackProfileBuilder::OnSampleCompleted(
std::vector<base::Frame> frames) { std::vector<base::Frame> frames,
OnSampleCompleted(std::move(frames), 1, 1); base::TimeTicks sample_timestamp) {
OnSampleCompleted(std::move(frames), sample_timestamp, 1, 1);
} }
void CallStackProfileBuilder::OnSampleCompleted(std::vector<base::Frame> frames, void CallStackProfileBuilder::OnSampleCompleted(
size_t weight, std::vector<base::Frame> frames,
size_t count) { base::TimeTicks sample_timestamp,
size_t weight,
size_t count) {
// Write CallStackProfile::Stack protobuf message. // Write CallStackProfile::Stack protobuf message.
CallStackProfile::Stack stack; CallStackProfile::Stack stack;
......
...@@ -66,6 +66,7 @@ class CallStackProfileBuilder : public base::ProfileBuilder { ...@@ -66,6 +66,7 @@ class CallStackProfileBuilder : public base::ProfileBuilder {
// Both weight and count are used by the heap profiler only. // Both weight and count are used by the heap profiler only.
void OnSampleCompleted(std::vector<base::Frame> frames, void OnSampleCompleted(std::vector<base::Frame> frames,
base::TimeTicks sample_timestamp,
size_t weight, size_t weight,
size_t count); size_t count);
...@@ -73,7 +74,8 @@ class CallStackProfileBuilder : public base::ProfileBuilder { ...@@ -73,7 +74,8 @@ class CallStackProfileBuilder : public base::ProfileBuilder {
base::ModuleCache* GetModuleCache() override; base::ModuleCache* GetModuleCache() override;
void RecordMetadata( void RecordMetadata(
base::ProfileBuilder::MetadataProvider* metadata_provider) override; base::ProfileBuilder::MetadataProvider* metadata_provider) override;
void OnSampleCompleted(std::vector<base::Frame> frames) override; void OnSampleCompleted(std::vector<base::Frame> frames,
base::TimeTicks sample_timestamp) override;
void OnProfileCompleted(base::TimeDelta profile_duration, void OnProfileCompleted(base::TimeDelta profile_duration,
base::TimeDelta sampling_period) override; base::TimeDelta sampling_period) override;
......
...@@ -118,10 +118,10 @@ TEST(CallStackProfileBuilderTest, ProfilingCompleted) { ...@@ -118,10 +118,10 @@ TEST(CallStackProfileBuilderTest, ProfilingCompleted) {
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames1); profile_builder->OnSampleCompleted(frames1, base::TimeTicks());
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames2); profile_builder->OnSampleCompleted(frames2, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500), profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500),
base::TimeDelta::FromMilliseconds(100)); base::TimeDelta::FromMilliseconds(100));
...@@ -183,9 +183,9 @@ TEST(CallStackProfileBuilderTest, CustomWeightsAndCounts) { ...@@ -183,9 +183,9 @@ TEST(CallStackProfileBuilderTest, CustomWeightsAndCounts) {
base::Frame frame1 = {0x10, &module1}; base::Frame frame1 = {0x10, &module1};
std::vector<base::Frame> frames = {frame1}; std::vector<base::Frame> frames = {frame1};
profile_builder->OnSampleCompleted(frames, 42, 3); profile_builder->OnSampleCompleted(frames, base::TimeTicks(), 42, 3);
profile_builder->OnSampleCompleted(frames, 1, 1); profile_builder->OnSampleCompleted(frames, base::TimeTicks(), 1, 1);
profile_builder->OnSampleCompleted(frames); profile_builder->OnSampleCompleted(frames, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
const SampledProfile& proto = profile_builder->test_sampled_profile(); const SampledProfile& proto = profile_builder->test_sampled_profile();
...@@ -219,10 +219,10 @@ TEST(CallStackProfileBuilderTest, StacksDeduped) { ...@@ -219,10 +219,10 @@ TEST(CallStackProfileBuilderTest, StacksDeduped) {
// to one. // to one.
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames); profile_builder->OnSampleCompleted(frames, base::TimeTicks());
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames); profile_builder->OnSampleCompleted(frames, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
...@@ -259,10 +259,10 @@ TEST(CallStackProfileBuilderTest, StacksNotDeduped) { ...@@ -259,10 +259,10 @@ TEST(CallStackProfileBuilderTest, StacksNotDeduped) {
// Two stacks are completed with the different frames therefore not deduped. // Two stacks are completed with the different frames therefore not deduped.
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames1); profile_builder->OnSampleCompleted(frames1, base::TimeTicks());
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames2); profile_builder->OnSampleCompleted(frames2, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
...@@ -305,7 +305,7 @@ TEST(CallStackProfileBuilderTest, Modules) { ...@@ -305,7 +305,7 @@ TEST(CallStackProfileBuilderTest, Modules) {
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames); profile_builder->OnSampleCompleted(frames, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
const SampledProfile& proto = profile_builder->test_sampled_profile(); const SampledProfile& proto = profile_builder->test_sampled_profile();
...@@ -356,7 +356,7 @@ TEST(CallStackProfileBuilderTest, DedupModules) { ...@@ -356,7 +356,7 @@ TEST(CallStackProfileBuilderTest, DedupModules) {
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted(frames); profile_builder->OnSampleCompleted(frames, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta()); profile_builder->OnProfileCompleted(base::TimeDelta(), base::TimeDelta());
const SampledProfile& proto = profile_builder->test_sampled_profile(); const SampledProfile& proto = profile_builder->test_sampled_profile();
...@@ -408,25 +408,25 @@ TEST(CallStackProfileBuilderTest, WorkIds) { ...@@ -408,25 +408,25 @@ TEST(CallStackProfileBuilderTest, WorkIds) {
// not have continued_work set. // not have continued_work set.
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
// The second sample with the same id should have continued_work set. // The second sample with the same id should have continued_work set.
work_id_recorder.current_id = 1; work_id_recorder.current_id = 1;
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
// Ids are in general non-contiguous across multiple samples. // Ids are in general non-contiguous across multiple samples.
work_id_recorder.current_id = 10; work_id_recorder.current_id = 10;
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
base::MetadataRecorder().CreateMetadataProvider().get()); base::MetadataRecorder().CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500), profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500),
base::TimeDelta::FromMilliseconds(100)); base::TimeDelta::FromMilliseconds(100));
...@@ -458,7 +458,7 @@ TEST(CallStackProfileBuilderTest, RecordMetadata) { ...@@ -458,7 +458,7 @@ TEST(CallStackProfileBuilderTest, RecordMetadata) {
metadata_recorder.Set(100, base::nullopt, 10); metadata_recorder.Set(100, base::nullopt, 10);
profile_builder->RecordMetadata( profile_builder->RecordMetadata(
metadata_recorder.CreateMetadataProvider().get()); metadata_recorder.CreateMetadataProvider().get());
profile_builder->OnSampleCompleted({frame}); profile_builder->OnSampleCompleted({frame}, base::TimeTicks());
profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500), profile_builder->OnProfileCompleted(base::TimeDelta::FromMilliseconds(500),
base::TimeDelta::FromMilliseconds(100)); base::TimeDelta::FromMilliseconds(100));
......
...@@ -44,7 +44,7 @@ void StackSamplerAndroid::RecordStackFrames( ...@@ -44,7 +44,7 @@ void StackSamplerAndroid::RecordStackFrames(
uintptr_t address = reinterpret_cast<uintptr_t>(pcs[i]); uintptr_t address = reinterpret_cast<uintptr_t>(pcs[i]);
frames.emplace_back(address, module_cache_->GetModuleForAddress(address)); frames.emplace_back(address, module_cache_->GetModuleForAddress(address));
} }
profile_builder->OnSampleCompleted(std::move(frames)); profile_builder->OnSampleCompleted(std::move(frames), TRACE_TIME_TICKS_NOW());
} }
} // namespace tracing } // namespace tracing
...@@ -210,12 +210,13 @@ TracingSamplerProfiler::TracingProfileBuilder::GetModuleCache() { ...@@ -210,12 +210,13 @@ TracingSamplerProfiler::TracingProfileBuilder::GetModuleCache() {
} }
void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted( void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted(
std::vector<base::Frame> frames) { std::vector<base::Frame> frames,
base::TimeTicks sample_timestamp) {
base::AutoLock l(trace_writer_lock_); base::AutoLock l(trace_writer_lock_);
if (!trace_writer_) { if (!trace_writer_) {
if (buffered_samples_.size() < kMaxBufferedSamples) { if (buffered_samples_.size() < kMaxBufferedSamples) {
buffered_samples_.emplace_back( buffered_samples_.emplace_back(
BufferedSample(TRACE_TIME_TICKS_NOW(), std::move(frames))); BufferedSample(sample_timestamp, std::move(frames)));
} }
return; return;
} }
...@@ -225,7 +226,7 @@ void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted( ...@@ -225,7 +226,7 @@ void TracingSamplerProfiler::TracingProfileBuilder::OnSampleCompleted(
} }
buffered_samples_.clear(); buffered_samples_.clear();
} }
WriteSampleToTrace(BufferedSample(TRACE_TIME_TICKS_NOW(), std::move(frames))); WriteSampleToTrace(BufferedSample(sample_timestamp, std::move(frames)));
} }
void TracingSamplerProfiler::TracingProfileBuilder::WriteSampleToTrace( void TracingSamplerProfiler::TracingProfileBuilder::WriteSampleToTrace(
......
...@@ -47,7 +47,8 @@ class COMPONENT_EXPORT(TRACING_CPP) TracingSamplerProfiler { ...@@ -47,7 +47,8 @@ class COMPONENT_EXPORT(TRACING_CPP) TracingSamplerProfiler {
// base::ProfileBuilder // base::ProfileBuilder
base::ModuleCache* GetModuleCache() override; base::ModuleCache* GetModuleCache() override;
void OnSampleCompleted(std::vector<base::Frame> frames) override; void OnSampleCompleted(std::vector<base::Frame> frames,
base::TimeTicks sample_timestamp) override;
void OnProfileCompleted(base::TimeDelta profile_duration, void OnProfileCompleted(base::TimeDelta profile_duration,
base::TimeDelta sampling_period) override {} base::TimeDelta sampling_period) override {}
......
...@@ -358,14 +358,16 @@ TEST(TracingProfileBuilderTest, ValidModule) { ...@@ -358,14 +358,16 @@ TEST(TracingProfileBuilderTest, ValidModule) {
TracingSamplerProfiler::TracingProfileBuilder profile_builder( TracingSamplerProfiler::TracingProfileBuilder profile_builder(
base::PlatformThreadId(), base::PlatformThreadId(),
std::make_unique<MockTraceWriter>(base::DoNothing()), false); std::make_unique<MockTraceWriter>(base::DoNothing()), false);
profile_builder.OnSampleCompleted({base::Frame(0x1010, &module)}); profile_builder.OnSampleCompleted({base::Frame(0x1010, &module)},
base::TimeTicks());
} }
TEST(TracingProfileBuilderTest, InvalidModule) { TEST(TracingProfileBuilderTest, InvalidModule) {
TracingSamplerProfiler::TracingProfileBuilder profile_builder( TracingSamplerProfiler::TracingProfileBuilder profile_builder(
base::PlatformThreadId(), base::PlatformThreadId(),
std::make_unique<MockTraceWriter>(base::DoNothing()), false); std::make_unique<MockTraceWriter>(base::DoNothing()), false);
profile_builder.OnSampleCompleted({base::Frame(0x1010, nullptr)}); profile_builder.OnSampleCompleted({base::Frame(0x1010, nullptr)},
base::TimeTicks());
} }
#if defined(OS_ANDROID) || defined(OS_LINUX) #if defined(OS_ANDROID) || defined(OS_LINUX)
...@@ -392,7 +394,8 @@ TEST(TracingProfileBuilderTest, MangleELFModuleID) { ...@@ -392,7 +394,8 @@ TEST(TracingProfileBuilderTest, MangleELFModuleID) {
auto* raw_trace_writer = trace_writer.get(); auto* raw_trace_writer = trace_writer.get();
TracingSamplerProfiler::TracingProfileBuilder profile_builder( TracingSamplerProfiler::TracingProfileBuilder profile_builder(
base::PlatformThreadId(), std::move(trace_writer), false); base::PlatformThreadId(), std::move(trace_writer), false);
profile_builder.OnSampleCompleted({base::Frame(0x1010, &module)}); profile_builder.OnSampleCompleted({base::Frame(0x1010, &module)},
base::TimeTicks());
raw_trace_writer->FlushPacketIfPossible(); raw_trace_writer->FlushPacketIfPossible();
EXPECT_TRUE(found_build_id); EXPECT_TRUE(found_build_id);
} }
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment