Bug 1551355 - Use TimeStamp::NowUnfuzzed() instead of TimeStamp::Now() during gecko profiling r=mstange

The profiler will require non-fuzzed timers for accuracy.  Making the switch early will avoid surprises when FuzzyFox is enabled.

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

--HG--
extra : moz-landing-system : lando
This commit is contained in:
Denis Palmeiro 2019-06-10 17:35:42 +00:00
parent 8da85f8ef1
commit c32ed0ea49
14 changed files with 52 additions and 52 deletions

View File

@ -69,7 +69,7 @@ void gecko_profiler_add_text_marker(const char* name, const char* text_bytes,
size_t text_len, uint64_t microseconds) {
#ifdef MOZ_GECKO_PROFILER
if (profiler_thread_is_being_profiled()) {
auto now = mozilla::TimeStamp::Now();
auto now = mozilla::TimeStamp::NowUnfuzzed();
auto start = now - mozilla::TimeDuration::FromMicroseconds(microseconds);
profiler_add_text_marker(name, nsDependentCSubstring(text_bytes, text_len),
JS::ProfilingCategoryPair::GRAPHICS, start, now);

View File

@ -117,7 +117,7 @@ void TraceLoggerThread::initGraph() {
MOZ_ASSERT(traceLoggerState);
bool graphFile = traceLoggerState->isGraphFileEnabled();
double delta =
traceLoggerState->getTimeStampOffset(mozilla::TimeStamp::Now());
traceLoggerState->getTimeStampOffset(mozilla::TimeStamp::NowUnfuzzed());
uint64_t start = static_cast<uint64_t>(delta);
if (!graph_->init(start, graphFile)) {
graph_ = nullptr;
@ -971,7 +971,7 @@ void TraceLoggerThread::log(uint32_t id) {
// we record the time it took to make more space. To log this information
// we need 2 extra free entries.
if (!events_.hasSpaceForAdd(3)) {
mozilla::TimeStamp start = mozilla::TimeStamp::Now();
mozilla::TimeStamp start = mozilla::TimeStamp::NowUnfuzzed();
if (!events_.ensureSpaceBeforeAdd(3)) {
if (graph_.get()) {
@ -1001,12 +1001,12 @@ void TraceLoggerThread::log(uint32_t id) {
entryStart.textId = TraceLogger_Internal;
EventEntry& entryStop = events_.pushUninitialized();
entryStop.time = mozilla::TimeStamp::Now();
entryStop.time = mozilla::TimeStamp::NowUnfuzzed();
entryStop.textId = TraceLogger_Stop;
}
}
mozilla::TimeStamp time = mozilla::TimeStamp::Now();
mozilla::TimeStamp time = mozilla::TimeStamp::NowUnfuzzed();
EventEntry& entry = events_.pushUninitialized();
entry.time = time;
@ -1256,7 +1256,7 @@ bool TraceLoggerThreadState::init() {
spewErrors = false;
}
startTime = mozilla::TimeStamp::Now();
startTime = mozilla::TimeStamp::NowUnfuzzed();
#ifdef DEBUG
initialized = true;

View File

@ -1267,7 +1267,7 @@ bool ProfileBuffer::DuplicateLastSample(int aThreadId,
case ProfileBufferEntry::Kind::Time:
// Copy with new time
AddEntry(ProfileBufferEntry::Time(
(TimeStamp::Now() - aProcessStartTime).ToMilliseconds()));
(TimeStamp::NowUnfuzzed() - aProcessStartTime).ToMilliseconds()));
break;
case ProfileBufferEntry::Kind::Marker:
case ProfileBufferEntry::Kind::ResidentMemory:

View File

@ -56,7 +56,7 @@ class ProfiledThreadData final {
MOZ_ASSERT(!mBufferPositionWhenReceivedJSContext,
"JSContext should have been cleared before the thread was "
"unregistered");
mUnregisterTime = TimeStamp::Now();
mUnregisterTime = TimeStamp::NowUnfuzzed();
mBufferPositionWhenUnregistered = Some(aBufferPosition);
}
Maybe<uint64_t> BufferPositionWhenUnregistered() {

View File

@ -20,7 +20,7 @@ namespace baseprofiler {
class ThreadInfo final {
public:
ThreadInfo(const char* aName, int aThreadId, bool aIsMainThread,
const TimeStamp& aRegisterTime = TimeStamp::Now())
const TimeStamp& aRegisterTime = TimeStamp::NowUnfuzzed())
: mName(aName),
mRegisterTime(aRegisterTime),
mThreadId(aThreadId),

View File

@ -239,7 +239,7 @@ void SamplerThread::SleepMicro(uint32_t aMicroseconds) {
if (mIntervalMicroseconds >= 1000) {
::Sleep(std::max(1u, aMicroseconds / 1000));
} else {
TimeStamp start = TimeStamp::Now();
TimeStamp start = TimeStamp::NowUnfuzzed();
TimeStamp end = start + TimeDuration::FromMicroseconds(aMicroseconds);
// First, sleep for as many whole milliseconds as possible.
@ -248,7 +248,7 @@ void SamplerThread::SleepMicro(uint32_t aMicroseconds) {
}
// Then, spin until enough time has passed.
while (TimeStamp::Now() < end) {
while (TimeStamp::NowUnfuzzed() < end) {
YieldProcessor();
}
}

View File

@ -1527,7 +1527,7 @@ static void StreamMetaJSCustomObject(PSLockRef aLock,
// The "startTime" field holds the number of milliseconds since midnight
// January 1, 1970 GMT. This grotty code computes (Now - (Now -
// ProcessStartTime)) to convert CorePS::ProcessStartTime() into that form.
TimeDuration delta = TimeStamp::Now() - CorePS::ProcessStartTime();
TimeDuration delta = TimeStamp::NowUnfuzzed() - CorePS::ProcessStartTime();
aWriter.DoubleProperty(
"startTime", MicrosecondsSince1970() / 1000.0 - delta.ToMilliseconds());
@ -1913,13 +1913,13 @@ void SamplerThread::Run() {
// This will be positive if we are running behind schedule (sampling less
// frequently than desired) and negative if we are ahead of schedule.
TimeDuration lastSleepOvershoot = 0;
TimeStamp sampleStart = TimeStamp::Now();
TimeStamp sampleStart = TimeStamp::NowUnfuzzed();
while (true) {
// This scope is for |lock|. It ends before we sleep below.
{
PSAutoLock lock;
TimeStamp lockAcquired = TimeStamp::Now();
TimeStamp lockAcquired = TimeStamp::NowUnfuzzed();
if (!ActivePS::Exists(lock)) {
return;
@ -1935,7 +1935,7 @@ void SamplerThread::Run() {
ActivePS::ClearExpiredExitProfiles(lock);
ActivePS::Buffer(lock).DeleteExpiredStoredMarkers();
TimeStamp expiredMarkersCleaned = TimeStamp::Now();
TimeStamp expiredMarkersCleaned = TimeStamp::NowUnfuzzed();
if (!ActivePS::IsPaused(lock)) {
const Vector<LiveProfiledThreadData>& liveThreads =
@ -1946,7 +1946,7 @@ void SamplerThread::Run() {
// handle per-process generic counters
const Vector<BaseProfilerCount*>& counters = CorePS::Counters(lock);
TimeStamp now = TimeStamp::Now();
TimeStamp now = TimeStamp::NowUnfuzzed();
for (auto& counter : counters) {
// create Buffer entries for each counter
buffer.AddEntry(ProfileBufferEntry::CounterId(counter));
@ -1964,7 +1964,7 @@ void SamplerThread::Run() {
buffer.AddEntry(ProfileBufferEntry::Number(number));
}
}
TimeStamp countersSampled = TimeStamp::Now();
TimeStamp countersSampled = TimeStamp::NowUnfuzzed();
for (auto& thread : liveThreads) {
RegisteredThread* registeredThread = thread.mRegisteredThread;
@ -1985,7 +1985,7 @@ void SamplerThread::Run() {
}
}
now = TimeStamp::Now();
now = TimeStamp::NowUnfuzzed();
SuspendAndSampleAndResumeThread(
lock, *registeredThread, [&](const Registers& aRegs) {
DoPeriodicSample(lock, *registeredThread, *profiledThreadData,
@ -2001,7 +2001,7 @@ void SamplerThread::Run() {
// SuspendAndSampleAndResumeThread, which is why it is done here.
CorePS::Lul(lock)->MaybeShowStats();
# endif
TimeStamp threadsSampled = TimeStamp::Now();
TimeStamp threadsSampled = TimeStamp::NowUnfuzzed();
buffer.AddEntry(
ProfileBufferEntry::ProfilerOverheadTime(delta.ToMilliseconds()));
@ -2018,7 +2018,7 @@ void SamplerThread::Run() {
Maybe<double> duration = ActivePS::Duration(lock);
if (duration) {
ActivePS::Buffer(lock).DiscardSamplesBeforeTime(
(TimeStamp::Now() - TimeDuration::FromSeconds(*duration) -
(TimeStamp::NowUnfuzzed() - TimeDuration::FromSeconds(*duration) -
CorePS::ProcessStartTime())
.ToMilliseconds());
}
@ -2032,12 +2032,12 @@ void SamplerThread::Run() {
// actual sleep intervals.
TimeStamp targetSleepEndTime =
sampleStart + TimeDuration::FromMicroseconds(mIntervalMicroseconds);
TimeStamp beforeSleep = TimeStamp::Now();
TimeStamp beforeSleep = TimeStamp::NowUnfuzzed();
TimeDuration targetSleepDuration = targetSleepEndTime - beforeSleep;
double sleepTime = std::max(
0.0, (targetSleepDuration - lastSleepOvershoot).ToMicroseconds());
SleepMicro(static_cast<uint32_t>(sleepTime));
sampleStart = TimeStamp::Now();
sampleStart = TimeStamp::NowUnfuzzed();
lastSleepOvershoot =
sampleStart - (beforeSleep + TimeDuration::FromMicroseconds(sleepTime));
}
@ -3045,7 +3045,7 @@ bool profiler_thread_is_sleeping() {
double profiler_time() {
MOZ_RELEASE_ASSERT(CorePS::Exists());
TimeDuration delta = TimeStamp::Now() - CorePS::ProcessStartTime();
TimeDuration delta = TimeStamp::NowUnfuzzed() - CorePS::ProcessStartTime();
return delta.ToMilliseconds();
}
@ -3067,7 +3067,7 @@ UniqueProfilerBacktrace profiler_get_backtrace() {
int tid = profiler_current_thread_id();
TimeStamp now = TimeStamp::Now();
TimeStamp now = TimeStamp::NowUnfuzzed();
Registers regs;
# if defined(HAVE_NATIVE_UNWIND)
@ -3109,7 +3109,7 @@ static void racy_profiler_add_marker(
TimeStamp origin = (aPayload && !aPayload->GetStartTime().IsNull())
? aPayload->GetStartTime()
: TimeStamp::Now();
: TimeStamp::NowUnfuzzed();
TimeDuration delta = origin - CorePS::ProcessStartTime();
racyRegisteredThread->AddPendingMarker(
aMarkerName, aCategoryPair, std::move(aPayload), delta.ToMilliseconds());
@ -3155,7 +3155,7 @@ void profiler_add_marker_for_thread(int aThreadId,
// Create the ProfilerMarker which we're going to store.
TimeStamp origin = (aPayload && !aPayload->GetStartTime().IsNull())
? aPayload->GetStartTime()
: TimeStamp::Now();
: TimeStamp::NowUnfuzzed();
TimeDuration delta = origin - CorePS::ProcessStartTime();
ProfilerMarker* marker =
new ProfilerMarker(aMarkerName, aCategoryPair, aThreadId,

View File

@ -705,7 +705,7 @@ class MOZ_RAII AutoProfilerTextMarker {
: mMarkerName(aMarkerName),
mText(aText),
mCategoryPair(aCategoryPair),
mStartTime(TimeStamp::Now()),
mStartTime(TimeStamp::NowUnfuzzed()),
mCause(std::move(aCause)),
mDocShellId(aDocShellId),
mDocShellHistoryId(aDocShellHistoryId) {
@ -714,7 +714,7 @@ class MOZ_RAII AutoProfilerTextMarker {
~AutoProfilerTextMarker() {
profiler_add_text_marker(mMarkerName, mText, mCategoryPair, mStartTime,
TimeStamp::Now(), mDocShellId, mDocShellHistoryId,
TimeStamp::NowUnfuzzed(), mDocShellId, mDocShellHistoryId,
std::move(mCause));
}

View File

@ -1661,7 +1661,7 @@ bool ProfileBuffer::DuplicateLastSample(int aThreadId,
case ProfileBufferEntry::Kind::Time:
// Copy with new time
AddEntry(ProfileBufferEntry::Time(
(TimeStamp::Now() - aProcessStartTime).ToMilliseconds()));
(TimeStamp::NowUnfuzzed() - aProcessStartTime).ToMilliseconds()));
break;
case ProfileBufferEntry::Kind::Marker:
case ProfileBufferEntry::Kind::ResidentMemory:

View File

@ -53,7 +53,7 @@ class ProfiledThreadData final {
MOZ_ASSERT(!mBufferPositionWhenReceivedJSContext,
"JSContext should have been cleared before the thread was "
"unregistered");
mUnregisterTime = mozilla::TimeStamp::Now();
mUnregisterTime = mozilla::TimeStamp::NowUnfuzzed();
mBufferPositionWhenUnregistered = mozilla::Some(aBufferPosition);
}
mozilla::Maybe<uint64_t> BufferPositionWhenUnregistered() {

View File

@ -19,9 +19,9 @@ class ThreadInfo final {
public:
NS_INLINE_DECL_THREADSAFE_REFCOUNTING(ThreadInfo)
ThreadInfo(
const char* aName, int aThreadId, bool aIsMainThread,
const mozilla::TimeStamp& aRegisterTime = mozilla::TimeStamp::Now())
ThreadInfo(const char* aName, int aThreadId, bool aIsMainThread,
const mozilla::TimeStamp& aRegisterTime =
mozilla::TimeStamp::NowUnfuzzed())
: mName(aName),
mRegisterTime(aRegisterTime),
mThreadId(aThreadId),

View File

@ -224,7 +224,7 @@ void SamplerThread::SleepMicro(uint32_t aMicroseconds) {
if (mIntervalMicroseconds >= 1000) {
::Sleep(std::max(1u, aMicroseconds / 1000));
} else {
TimeStamp start = TimeStamp::Now();
TimeStamp start = TimeStamp::NowUnfuzzed();
TimeStamp end = start + TimeDuration::FromMicroseconds(aMicroseconds);
// First, sleep for as many whole milliseconds as possible.
@ -233,7 +233,7 @@ void SamplerThread::SleepMicro(uint32_t aMicroseconds) {
}
// Then, spin until enough time has passed.
while (TimeStamp::Now() < end) {
while (TimeStamp::NowUnfuzzed() < end) {
YieldProcessor();
}
}

View File

@ -1854,7 +1854,7 @@ static void StreamMetaJSCustomObject(PSLockRef aLock,
// The "startTime" field holds the number of milliseconds since midnight
// January 1, 1970 GMT. This grotty code computes (Now - (Now -
// ProcessStartTime)) to convert CorePS::ProcessStartTime() into that form.
TimeDuration delta = TimeStamp::Now() - CorePS::ProcessStartTime();
TimeDuration delta = TimeStamp::NowUnfuzzed() - CorePS::ProcessStartTime();
aWriter.DoubleProperty(
"startTime",
static_cast<double>(PR_Now() / 1000.0 - delta.ToMilliseconds()));
@ -2445,13 +2445,13 @@ void SamplerThread::Run() {
// This will be positive if we are running behind schedule (sampling less
// frequently than desired) and negative if we are ahead of schedule.
TimeDuration lastSleepOvershoot = 0;
TimeStamp sampleStart = TimeStamp::Now();
TimeStamp sampleStart = TimeStamp::NowUnfuzzed();
while (true) {
// This scope is for |lock|. It ends before we sleep below.
{
PSAutoLock lock(gPSMutex);
TimeStamp lockAcquired = TimeStamp::Now();
TimeStamp lockAcquired = TimeStamp::NowUnfuzzed();
if (!ActivePS::Exists(lock)) {
return;
@ -2467,7 +2467,7 @@ void SamplerThread::Run() {
ActivePS::ClearExpiredExitProfiles(lock);
ActivePS::Buffer(lock).DeleteExpiredStoredMarkers();
TimeStamp expiredMarkersCleaned = TimeStamp::Now();
TimeStamp expiredMarkersCleaned = TimeStamp::NowUnfuzzed();
if (!ActivePS::IsPaused(lock)) {
const Vector<LiveProfiledThreadData>& liveThreads =
@ -2495,7 +2495,7 @@ void SamplerThread::Run() {
// handle per-process generic counters
const Vector<BaseProfilerCount*>& counters = CorePS::Counters(lock);
TimeStamp now = TimeStamp::Now();
TimeStamp now = TimeStamp::NowUnfuzzed();
for (auto& counter : counters) {
// create Buffer entries for each counter
buffer.AddEntry(ProfileBufferEntry::CounterId(counter));
@ -2513,7 +2513,7 @@ void SamplerThread::Run() {
buffer.AddEntry(ProfileBufferEntry::Number(number));
}
}
TimeStamp countersSampled = TimeStamp::Now();
TimeStamp countersSampled = TimeStamp::NowUnfuzzed();
for (auto& thread : liveThreads) {
RegisteredThread* registeredThread = thread.mRegisteredThread;
@ -2540,7 +2540,7 @@ void SamplerThread::Run() {
resp->Update();
}
now = TimeStamp::Now();
now = TimeStamp::NowUnfuzzed();
SuspendAndSampleAndResumeThread(
lock, *registeredThread, [&](const Registers& aRegs) {
DoPeriodicSample(lock, *registeredThread, *profiledThreadData,
@ -2561,7 +2561,7 @@ void SamplerThread::Run() {
// SuspendAndSampleAndResumeThread, which is why it is done here.
CorePS::Lul(lock)->MaybeShowStats();
#endif
TimeStamp threadsSampled = TimeStamp::Now();
TimeStamp threadsSampled = TimeStamp::NowUnfuzzed();
buffer.AddEntry(
ProfileBufferEntry::ProfilerOverheadTime(delta.ToMilliseconds()));
@ -2578,7 +2578,7 @@ void SamplerThread::Run() {
Maybe<double> duration = ActivePS::Duration(lock);
if (duration) {
ActivePS::Buffer(lock).DiscardSamplesBeforeTime(
(TimeStamp::Now() - TimeDuration::FromSeconds(*duration) -
(TimeStamp::NowUnfuzzed() - TimeDuration::FromSeconds(*duration) -
CorePS::ProcessStartTime())
.ToMilliseconds());
}
@ -2592,12 +2592,12 @@ void SamplerThread::Run() {
// actual sleep intervals.
TimeStamp targetSleepEndTime =
sampleStart + TimeDuration::FromMicroseconds(mIntervalMicroseconds);
TimeStamp beforeSleep = TimeStamp::Now();
TimeStamp beforeSleep = TimeStamp::NowUnfuzzed();
TimeDuration targetSleepDuration = targetSleepEndTime - beforeSleep;
double sleepTime = std::max(
0.0, (targetSleepDuration - lastSleepOvershoot).ToMicroseconds());
SleepMicro(static_cast<uint32_t>(sleepTime));
sampleStart = TimeStamp::Now();
sampleStart = TimeStamp::NowUnfuzzed();
lastSleepOvershoot =
sampleStart - (beforeSleep + TimeDuration::FromMicroseconds(sleepTime));
}
@ -3912,7 +3912,7 @@ void profiler_js_interrupt_callback() {
double profiler_time() {
MOZ_RELEASE_ASSERT(CorePS::Exists());
TimeDuration delta = TimeStamp::Now() - CorePS::ProcessStartTime();
TimeDuration delta = TimeStamp::NowUnfuzzed() - CorePS::ProcessStartTime();
return delta.ToMilliseconds();
}
@ -3934,7 +3934,7 @@ UniqueProfilerBacktrace profiler_get_backtrace() {
int tid = profiler_current_thread_id();
TimeStamp now = TimeStamp::Now();
TimeStamp now = TimeStamp::NowUnfuzzed();
Registers regs;
#if defined(HAVE_NATIVE_UNWIND)
@ -3976,7 +3976,7 @@ static void racy_profiler_add_marker(
TimeStamp origin = (aPayload && !aPayload->GetStartTime().IsNull())
? aPayload->GetStartTime()
: TimeStamp::Now();
: TimeStamp::NowUnfuzzed();
TimeDuration delta = origin - CorePS::ProcessStartTime();
racyRegisteredThread->AddPendingMarker(
aMarkerName, aCategoryPair, std::move(aPayload), delta.ToMilliseconds());
@ -4051,7 +4051,7 @@ void profiler_add_marker_for_thread(int aThreadId,
// Create the ProfilerMarker which we're going to store.
TimeStamp origin = (aPayload && !aPayload->GetStartTime().IsNull())
? aPayload->GetStartTime()
: TimeStamp::Now();
: TimeStamp::NowUnfuzzed();
TimeDuration delta = origin - CorePS::ProcessStartTime();
ProfilerMarker* marker =
new ProfilerMarker(aMarkerName, aCategoryPair, aThreadId,

View File

@ -750,7 +750,7 @@ class MOZ_RAII AutoProfilerTextMarker {
: mMarkerName(aMarkerName),
mText(aText),
mCategoryPair(aCategoryPair),
mStartTime(mozilla::TimeStamp::Now()),
mStartTime(mozilla::TimeStamp::NowUnfuzzed()),
mCause(std::move(aCause)),
mDocShellId(aDocShellId),
mDocShellHistoryId(aDocShellHistoryId) {
@ -759,7 +759,7 @@ class MOZ_RAII AutoProfilerTextMarker {
~AutoProfilerTextMarker() {
profiler_add_text_marker(mMarkerName, mText, mCategoryPair, mStartTime,
mozilla::TimeStamp::Now(), mDocShellId,
mozilla::TimeStamp::NowUnfuzzed(), mDocShellId,
mDocShellHistoryId, std::move(mCause));
}