Skip to content

Commit

Permalink
Bug 1578329 - profiler_can_accept_markers(), don't store markers when…
Browse files Browse the repository at this point in the history
… paused - r=gregtatum

profiler_can_accept_markers() is a fast and racy check that markers would
currently be stored, it should be used around potentially-expensive calls to
add markers.

And now markers are no longer stored when the profiler is paused. (Note that the
profiler is paused when a profile is being stored, this will help make this
operation faster.)

Differential Revision: https://phabricator.services.mozilla.com/D44434

--HG--
extra : moz-landing-system : lando
  • Loading branch information
squelart committed Sep 18, 2019
1 parent a8b053c commit 738f482
Show file tree
Hide file tree
Showing 5 changed files with 100 additions and 13 deletions.
24 changes: 21 additions & 3 deletions mozglue/baseprofiler/core/platform.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -901,6 +901,12 @@ void RacyFeatures::SetInactive() { sActiveAndFeatures = 0; }
/* static */
bool RacyFeatures::IsActive() { return uint32_t(sActiveAndFeatures) & Active; }

/* static */
void RacyFeatures::SetPaused() { sActiveAndFeatures |= Paused; }

/* static */
void RacyFeatures::SetUnpaused() { sActiveAndFeatures &= ~Paused; }

/* static */
bool RacyFeatures::IsActiveWithFeature(uint32_t aFeature) {
uint32_t af = sActiveAndFeatures; // copy it first
Expand All @@ -913,6 +919,12 @@ bool RacyFeatures::IsActiveWithoutPrivacy() {
return (af & Active) && !(af & ProfilerFeature::Privacy);
}

/* static */
bool RacyFeatures::IsActiveAndUnpausedWithoutPrivacy() {
uint32_t af = sActiveAndFeatures; // copy it first
return (af & Active) && !(af & (Paused | ProfilerFeature::Privacy));
}

// Each live thread has a RegisteredThread, and we store a reference to it in
// TLS. This class encapsulates that TLS.
class TLSRegisteredThread {
Expand Down Expand Up @@ -2933,6 +2945,7 @@ void profiler_pause() {
return;
}

RacyFeatures::SetPaused();
ActivePS::SetIsPaused(lock, true);
ActivePS::Buffer(lock).AddEntry(ProfileBufferEntry::Pause(profiler_time()));
}
Expand All @@ -2953,6 +2966,7 @@ void profiler_resume() {
ActivePS::Buffer(lock).AddEntry(
ProfileBufferEntry::Resume(profiler_time()));
ActivePS::SetIsPaused(lock, false);
RacyFeatures::SetUnpaused();
}
}

Expand Down Expand Up @@ -3195,7 +3209,7 @@ static void racy_profiler_add_marker(const char* aMarkerName,
MOZ_RELEASE_ASSERT(CorePS::Exists());

// This function is hot enough that we use RacyFeatures, not ActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand Down Expand Up @@ -3245,6 +3259,10 @@ void profiler_add_marker_for_thread(int aThreadId,
UniquePtr<ProfilerMarkerPayload> aPayload) {
MOZ_RELEASE_ASSERT(CorePS::Exists());

if (!profiler_can_accept_markers()) {
return;
}

# ifdef DEBUG
{
PSAutoLock lock;
Expand Down Expand Up @@ -3287,7 +3305,7 @@ void profiler_tracing(const char* aCategoryString, const char* aMarkerName,
VTUNE_TRACING(aMarkerName, aKind);

// This function is hot enough that we use RacyFeatures, notActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand All @@ -3307,7 +3325,7 @@ void profiler_tracing(const char* aCategoryString, const char* aMarkerName,
VTUNE_TRACING(aMarkerName, aKind);

// This function is hot enough that we use RacyFeatures, notActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand Down
26 changes: 23 additions & 3 deletions mozglue/baseprofiler/public/BaseProfiler.h
Original file line number Diff line number Diff line change
Expand Up @@ -200,18 +200,25 @@ class RacyFeatures {

MFBT_API static void SetInactive();

MFBT_API static void SetPaused();

MFBT_API static void SetUnpaused();

MFBT_API static bool IsActive();

MFBT_API static bool IsActiveWithFeature(uint32_t aFeature);

MFBT_API static bool IsActiveWithoutPrivacy();

MFBT_API static bool IsActiveAndUnpausedWithoutPrivacy();

private:
static const uint32_t Active = 1u << 31;
static constexpr uint32_t Active = 1u << 31;
static constexpr uint32_t Paused = 1u << 30;

// Ensure Active doesn't overlap with any of the feature bits.
// Ensure Active/Paused don't overlap with any of the feature bits.
# define NO_OVERLAP(n_, str_, Name_, desc_) \
static_assert(ProfilerFeature::Name_ != Active, "bad Active value");
static_assert(ProfilerFeature::Name_ != Paused, "bad feature value");

BASE_PROFILER_FOR_EACH_FEATURE(NO_OVERLAP);

Expand Down Expand Up @@ -403,6 +410,19 @@ inline bool profiler_is_active() {
return baseprofiler::detail::RacyFeatures::IsActive();
}

// Same as profiler_is_active(), but with the same extra checks that determine
// if the profiler would currently store markers. So this should be used before
// doing some potentially-expensive work that's used in a marker. E.g.:
//
// if (profiler_can_accept_markers()) {
// ExpensiveMarkerPayload expensivePayload = CreateExpensivePayload();
// BASE_PROFILER_ADD_MARKER_WITH_PAYLOAD(name, OTHER, expensivePayload);
// }
inline bool profiler_can_accept_markers() {
return baseprofiler::detail::RacyFeatures::
IsActiveAndUnpausedWithoutPrivacy();
}

// Is the profiler active, and is the current thread being profiled?
// (Same caveats and recommented usage as profiler_is_active().)
inline bool profiler_thread_is_being_profiled() {
Expand Down
17 changes: 13 additions & 4 deletions tools/profiler/core/platform.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -3770,6 +3770,7 @@ void profiler_pause() {
return;
}

RacyFeatures::SetPaused();
ActivePS::SetIsPaused(lock, true);
ActivePS::Buffer(lock).AddEntry(ProfileBufferEntry::Pause(profiler_time()));
}
Expand All @@ -3794,6 +3795,7 @@ void profiler_resume() {
ActivePS::Buffer(lock).AddEntry(
ProfileBufferEntry::Resume(profiler_time()));
ActivePS::SetIsPaused(lock, false);
RacyFeatures::SetUnpaused();
}

// gPSMutex must be unlocked when we notify, to avoid potential deadlocks.
Expand Down Expand Up @@ -4064,7 +4066,7 @@ static void racy_profiler_add_marker(const char* aMarkerName,
MOZ_RELEASE_ASSERT(CorePS::Exists());

// This function is hot enough that we use RacyFeatures, not ActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand Down Expand Up @@ -4107,6 +4109,9 @@ void profiler_add_js_marker(const char* aMarkerName) {
}

void profiler_add_js_allocation_marker(JS::RecordAllocationInfo&& info) {
if (!profiler_can_accept_markers()) {
return;
}
AUTO_PROFILER_STATS(add_marker_with_JsAllocationMarkerPayload);
profiler_add_marker(
"JS allocation", JS::ProfilingCategoryPair::JS,
Expand All @@ -4120,7 +4125,7 @@ void profiler_add_network_marker(
mozilla::net::CacheDisposition aCacheDisposition,
const mozilla::net::TimingStruct* aTimings, nsIURI* aRedirectURI,
UniqueProfilerBacktrace aSource) {
if (!profiler_is_active()) {
if (!profiler_can_accept_markers()) {
return;
}
// These do allocations/frees/etc; avoid if not active
Expand Down Expand Up @@ -4151,6 +4156,10 @@ void profiler_add_marker_for_thread(int aThreadId,
UniquePtr<ProfilerMarkerPayload> aPayload) {
MOZ_RELEASE_ASSERT(CorePS::Exists());

if (!profiler_can_accept_markers()) {
return;
}

#ifdef DEBUG
{
PSAutoLock lock(gPSMutex);
Expand Down Expand Up @@ -4192,7 +4201,7 @@ void profiler_tracing(const char* aCategoryString, const char* aMarkerName,
VTUNE_TRACING(aMarkerName, aKind);

// This function is hot enough that we use RacyFeatures, notActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand All @@ -4212,7 +4221,7 @@ void profiler_tracing(const char* aCategoryString, const char* aMarkerName,
VTUNE_TRACING(aMarkerName, aKind);

// This function is hot enough that we use RacyFeatures, notActivePS.
if (!RacyFeatures::IsActiveWithoutPrivacy()) {
if (!profiler_can_accept_markers()) {
return;
}

Expand Down
29 changes: 26 additions & 3 deletions tools/profiler/public/GeckoProfiler.h
Original file line number Diff line number Diff line change
Expand Up @@ -207,6 +207,10 @@ class RacyFeatures {

static void SetInactive() { sActiveAndFeatures = 0; }

static void SetPaused() { sActiveAndFeatures |= Paused; }

static void SetUnpaused() { sActiveAndFeatures &= ~Paused; }

static bool IsActive() { return uint32_t(sActiveAndFeatures) & Active; }

static bool IsActiveWithFeature(uint32_t aFeature) {
Expand All @@ -219,12 +223,18 @@ class RacyFeatures {
return (af & Active) && !(af & ProfilerFeature::Privacy);
}

static bool IsActiveAndUnpausedWithoutPrivacy() {
uint32_t af = sActiveAndFeatures; // copy it first
return (af & Active) && !(af & (Paused | ProfilerFeature::Privacy));
}

private:
static const uint32_t Active = 1u << 31;
static constexpr uint32_t Active = 1u << 31;
static constexpr uint32_t Paused = 1u << 30;

// Ensure Active doesn't overlap with any of the feature bits.
// Ensure Active/Paused don't overlap with any of the feature bits.
# define NO_OVERLAP(n_, str_, Name_, desc_) \
static_assert(ProfilerFeature::Name_ != Active, "bad Active value");
static_assert(ProfilerFeature::Name_ != Paused, "bad feature value");

PROFILER_FOR_EACH_FEATURE(NO_OVERLAP);

Expand Down Expand Up @@ -424,6 +434,19 @@ inline bool profiler_is_active() {
return mozilla::profiler::detail::RacyFeatures::IsActive();
}

// Same as profiler_is_active(), but with the same extra checks that determine
// if the profiler would currently store markers. So this should be used before
// doing some potentially-expensive work that's used in a marker. E.g.:
//
// if (profiler_can_accept_markers()) {
// ExpensiveMarkerPayload expensivePayload = CreateExpensivePayload();
// BASE_PROFILER_ADD_MARKER_WITH_PAYLOAD(name, OTHER, expensivePayload);
// }
inline bool profiler_can_accept_markers() {
return mozilla::profiler::detail::RacyFeatures::
IsActiveAndUnpausedWithoutPrivacy();
}

// Is the profiler active, and is the current thread being profiled?
// (Same caveats and recommented usage as profiler_is_active().)
inline bool profiler_thread_is_being_profiled() {
Expand Down
17 changes: 17 additions & 0 deletions tools/profiler/tests/gtest/GeckoProfiler.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -458,35 +458,52 @@ TEST(GeckoProfiler, Pause)
const char* filters[] = {"GeckoMain"};

ASSERT_TRUE(!profiler_is_paused());
ASSERT_TRUE(!profiler_can_accept_markers());

profiler_start(PROFILER_DEFAULT_ENTRIES, PROFILER_DEFAULT_INTERVAL, features,
filters, MOZ_ARRAY_LENGTH(filters));

ASSERT_TRUE(!profiler_is_paused());
ASSERT_TRUE(profiler_can_accept_markers());

// Check that we are writing samples while not paused.
Maybe<ProfilerBufferInfo> info1 = profiler_get_buffer_info();
PR_Sleep(PR_MillisecondsToInterval(500));
Maybe<ProfilerBufferInfo> info2 = profiler_get_buffer_info();
ASSERT_TRUE(info1->mRangeEnd != info2->mRangeEnd);

// Check that we are writing markers while not paused.
info1 = profiler_get_buffer_info();
PROFILER_ADD_MARKER("Not paused", OTHER);
info2 = profiler_get_buffer_info();
ASSERT_TRUE(info1->mRangeEnd != info2->mRangeEnd);

profiler_pause();

ASSERT_TRUE(profiler_is_paused());
ASSERT_TRUE(!profiler_can_accept_markers());

// Check that we are not writing samples while paused.
info1 = profiler_get_buffer_info();
PR_Sleep(PR_MillisecondsToInterval(500));
info2 = profiler_get_buffer_info();
ASSERT_TRUE(info1->mRangeEnd == info2->mRangeEnd);

// Check that we are now writing markers while paused.
info1 = profiler_get_buffer_info();
PROFILER_ADD_MARKER("Paused", OTHER);
info2 = profiler_get_buffer_info();
ASSERT_TRUE(info1->mRangeEnd == info2->mRangeEnd);

profiler_resume();

ASSERT_TRUE(!profiler_is_paused());
ASSERT_TRUE(profiler_can_accept_markers());

profiler_stop();

ASSERT_TRUE(!profiler_is_paused());
ASSERT_TRUE(!profiler_can_accept_markers());
}

// A class that keeps track of how many instances have been created, streamed,
Expand Down

0 comments on commit 738f482

Please sign in to comment.