Magic-Mirror/gecko-dev
1
0
Fork 0
mirror of https://github.com/mozilla/gecko-dev.git synced 2024-11-29 15:52:07 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Bug 1181175 - Use RDTSC for Performance Monitoring instead of getrusage. r=jandem

Browse Source 
--HG--
extra : transplant_source : %8D%A9%CC%17Dj9-%81T%B2%0D%E1%EA%BD%05%C7%DCl%CB
This commit is contained in:
David Rajchenbach-Teller 2015-07-07 18:45:54 +02:00
parent 5d76bd45e9
commit d326242e8b
8 changed files with 678 additions and 235 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3
js/ipc/CPOWTimer.cpp
View File

@ -41,6 +41,5 @@ CPOWTimer::~CPOWTimer()
return;
}
js::PerformanceData* performance = js::GetPerformanceData(runtime);
performance->totalCPOWTime += endInterval - startInterval_;
js::AddCPOWPerformanceDelta(runtime, endInterval - startInterval_);
}

74
js/src/jsapi.h
View File

@ -5425,6 +5425,7 @@ class AutoStopwatch;
// Container for performance data
// All values are monotonic.
// All values are updated after running to completion.
struct PerformanceData {
// Number of times we have spent at least 2^n consecutive
// milliseconds executing code in this group.
@ -5491,30 +5492,68 @@ struct PerformanceGroup {
// An id unique to this runtime.
const uint64_t uid;
// The number of cycles spent in this group during this iteration
// of the event loop. Note that cycles are not a reliable measure,
// especially over short intervals. See Runtime.cpp for a more
// complete discussion on the imprecision of cycle measurement.
uint64_t recentCycles;
// The number of times this group has been activated during this
// iteration of the event loop.
uint64_t recentTicks;
// The number of milliseconds spent doing CPOW during this
// iteration of the event loop.
uint64_t recentCPOW;
// The current iteration of the event loop.
uint64_t iteration() const {
return iteration_;
}
// `true` if an instance of `AutoStopwatch` is already monitoring
// the performance of this performance group for this iteration
// of the event loop, `false` otherwise.
bool hasStopwatch(uint64_t iteration) const {
return stopwatch_ != nullptr && iteration_ == iteration;
bool hasStopwatch(uint64_t it) const {
return stopwatch_ != nullptr && iteration_ == it;
}
// `true` if a specific instance of `AutoStopwatch` is already monitoring
// the performance of this performance group for this iteration
// of the event loop, `false` otherwise.
bool hasStopwatch(uint64_t it, const AutoStopwatch* stopwatch) const {
return stopwatch_ == stopwatch && iteration_ == it;
}
// Mark that an instance of `AutoStopwatch` is monitoring
// the performance of this group for a given iteration.
void acquireStopwatch(uint64_t iteration, const AutoStopwatch* stopwatch) {
iteration_ = iteration;
void acquireStopwatch(uint64_t it, const AutoStopwatch* stopwatch) {
if (iteration_ != it) {
// Any data that pretends to be recent is actually bound
// to an older iteration and therefore stale.
resetRecentData();
}
iteration_ = it;
stopwatch_ = stopwatch;
}
// Mark that no `AutoStopwatch` is monitoring the
// performance of this group for the iteration.
void releaseStopwatch(uint64_t iteration, const AutoStopwatch* stopwatch) {
if (iteration_ != iteration)
void releaseStopwatch(uint64_t it, const AutoStopwatch* stopwatch) {
if (iteration_ != it)
return;
MOZ_ASSERT(stopwatch == stopwatch_ || stopwatch_ == nullptr);
stopwatch_ = nullptr;
}
// Get rid of any data that pretends to be recent.
void resetRecentData() {
recentCycles = 0;
recentTicks = 0;
recentCPOW = 0;
}
// Refcounting. For use with mozilla::RefPtr.
void AddRef();
void Release();
@ -5542,10 +5581,9 @@ private:
// The hash key for this PerformanceGroup.
void* const key_;
// A reference counter.
// Refcounter.
uint64_t refCount_;
// `true` if this PerformanceGroup may be shared by several
// compartments, `false` if it is dedicated to a single
// compartment.
@ -5605,12 +5643,19 @@ struct PerformanceGroupHolder {
};
/**
* Reset any stopwatch currently measuring.
* Commit any Performance Monitoring data.
*
* This function is designed to be called when we process a new event.
* Until `FlushMonitoring` has been called, all PerformanceMonitoring data is invisible
* to the outside world and can cancelled with a call to `ResetMonitoring`.
*/
extern JS_PUBLIC_API(void)
ResetStopwatches(JSRuntime*);
FlushPerformanceMonitoring(JSRuntime*);
/**
* Cancel any measurement that hasn't been committed.
*/
extern JS_PUBLIC_API(void)
ResetPerformanceMonitoring(JSRuntime*);
/**
* Turn on/off stopwatch-based CPU monitoring.
@ -5636,10 +5681,11 @@ extern JS_PUBLIC_API(bool)
IsStopwatchActive(JSRuntime*);
/**
* Access the performance information stored in a compartment.
* Add a number of microseconds to the time spent waiting on CPOWs
* since process start.
*/
extern JS_PUBLIC_API(PerformanceData*)
GetPerformanceData(JSRuntime*);
extern JS_PUBLIC_API(void)
AddCPOWPerformanceDelta(JSRuntime*, uint64_t delta);
typedef bool
(PerformanceStatsWalker)(JSContext* cx,

286
js/src/vm/Interpreter.cpp
View File

@ -56,14 +56,10 @@
#include "vm/ScopeObject-inl.h"
#include "vm/Stack-inl.h"
#if defined(XP_MACOSX)
#include <mach/mach.h>
#elif defined(XP_UNIX)
#include <sys/resource.h>
#elif defined(XP_WIN)
#include <processthreadsapi.h>
#include <windows.h>
#endif // defined(XP_MACOSX) || defined(XP_UNIX) || defined(XP_WIN)
#if defined(XP_WIN)
#include <Windows.h>
#include <Processthreadsapi.h>
#endif // defined(XP_WIN)
using namespace js;
using namespace js::gc;
@ -395,25 +391,47 @@ class AutoStopwatch final
bool isMonitoringCPOW_;
// Timestamps captured while starting the stopwatch.
uint64_t userTimeStart_;
uint64_t systemTimeStart_;
uint64_t cyclesStart_;
uint64_t CPOWTimeStart_;
// The performance group shared by this compartment and possibly
// others, or `nullptr` if another AutoStopwatch is already in
// charge of monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> sharedGroup_;
// The CPU on which we started the measure. Defined only
// if `isMonitoringJank_` is `true`.
#if defined(XP_WIN) && _WIN32_WINNT >= 0x0601
struct cpuid_t {
WORD group_;
BYTE number_;
cpuid_t(WORD group, BYTE number)
: group_(group),
number_(number)
{ }
cpuid_t()
: group_(0),
number_(0)
{ }
};
#elif defined(XP_LINUX)
typedef int cpuid_t;
#else
typedef struct {} cpuid_t;
#endif // defined(XP_WIN) || defined(XP_LINUX)
// The toplevel group, representing the entire process, or `nullptr`
// if another AutoStopwatch is already in charge of monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> topGroup_;
cpuid_t cpuStart_;
// The performance group specific to this compartment, or
// `nullptr` if another AutoStopwatch is already in charge of
// monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> ownGroup_;
// The performance group shared by this compartment and possibly
// others, or `nullptr` if another AutoStopwatch is already in
// charge of monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> sharedGroup_;
public:
// The toplevel group, representing the entire process, or `nullptr`
// if another AutoStopwatch is already in charge of monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> topGroup_;
// The performance group specific to this compartment, or
// `nullptr` if another AutoStopwatch is already in charge of
// monitoring that group.
mozilla::RefPtr<js::PerformanceGroup> ownGroup_;
public:
// If the stopwatch is active, constructing an instance of
// AutoStopwatch causes it to become the current owner of the
// stopwatch.
@ -424,8 +442,7 @@ class AutoStopwatch final
, iteration_(0)
, isMonitoringJank_(false)
, isMonitoringCPOW_(false)
, userTimeStart_(0)
, systemTimeStart_(0)
, cyclesStart_(0)
, CPOWTimeStart_(0)
{
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
@ -435,7 +452,7 @@ class AutoStopwatch final
return;
JSRuntime* runtime = cx_->runtime();
iteration_ = runtime->stopwatch.iteration;
iteration_ = runtime->stopwatch.iteration();
sharedGroup_ = acquireGroup(compartment->performanceMonitoring.getSharedGroup(cx));
if (sharedGroup_)
@ -449,14 +466,15 @@ class AutoStopwatch final
return;
}
// Now that we are sure that JS code is being executed,
// initialize the stopwatch for this iteration, lazily.
runtime->stopwatch.start();
enter();
}
~AutoStopwatch()
{
if (!sharedGroup_ && !ownGroup_) {
// We are not in charge of monitoring anything.
// (isMonitoringForTop_ implies isMonitoringForGroup_,
// so we do not need to check it)
return;
}
@ -465,32 +483,32 @@ class AutoStopwatch final
return;
JSRuntime* runtime = cx_->runtime();
if (iteration_ != runtime->stopwatch.iteration) {
if (iteration_ != runtime->stopwatch.iteration()) {
// We have entered a nested event loop at some point.
// Any information we may have is obsolete.
return;
}
// Finish and commit measures
exit();
releaseGroup(sharedGroup_);
releaseGroup(topGroup_);
releaseGroup(ownGroup_);
// Finish and commit measures
exit();
}
private:
void enter() {
JSRuntime* runtime = cx_->runtime();
if (runtime->stopwatch.isMonitoringCPOW()) {
CPOWTimeStart_ = runtime->stopwatch.performance.getOwnGroup()->data.totalCPOWTime;
CPOWTimeStart_ = runtime->stopwatch.totalCPOWTime;
isMonitoringCPOW_ = true;
}
if (runtime->stopwatch.isMonitoringJank()) {
if (this->getTimes(runtime, &userTimeStart_, &systemTimeStart_)) {
isMonitoringJank_ = true;
}
cyclesStart_ = this->getCycles();
cpuStart_ = this->getCPU();
isMonitoringJank_ = true;
}
}
@ -498,29 +516,31 @@ class AutoStopwatch final
void exit() {
JSRuntime* runtime = cx_->runtime();
uint64_t userTimeDelta = 0;
uint64_t systemTimeDelta = 0;
uint64_t cyclesDelta = 0;
if (isMonitoringJank_ && runtime->stopwatch.isMonitoringJank()) {
// We were monitoring jank when we entered and we still are.
uint64_t userTimeEnd, systemTimeEnd;
if (!this->getTimes(runtime, &userTimeEnd, &systemTimeEnd)) {
// We make no attempt to recover from this error. If
// we bail out here, we lose nothing of value, plus
// I'm nearly sure that this error cannot happen in
// practice.
return;
// If possible, discard results when we don't end on the
// same CPU as we started. Note that we can be
// rescheduled to another CPU beween `getCycles()` and
// `getCPU()`. We hope that this will happen rarely
// enough that the impact on our statistics will remain
// limited.
const cpuid_t cpuEnd = this->getCPU();
if (isSameCPU(cpuStart_, cpuEnd)) {
const uint64_t cyclesEnd = getCycles();
cyclesDelta = getDelta(cyclesEnd, cyclesStart_);
}
userTimeDelta = userTimeEnd - userTimeStart_;
systemTimeDelta = systemTimeEnd - systemTimeStart_;
}
uint64_t CPOWTimeDelta = 0;
if (isMonitoringCPOW_ && runtime->stopwatch.isMonitoringCPOW()) {
// We were monitoring CPOW when we entered and we still are.
CPOWTimeDelta = runtime->stopwatch.performance.getOwnGroup()->data.totalCPOWTime - CPOWTimeStart_;
const uint64_t CPOWTimeEnd = runtime->stopwatch.totalCPOWTime;
CPOWTimeDelta = getDelta(CPOWTimeEnd, CPOWTimeStart_);
}
commitDeltasToGroups(userTimeDelta, systemTimeDelta, CPOWTimeDelta);
addToGroups(cyclesDelta, CPOWTimeDelta);
}
// Attempt to acquire a group
@ -547,121 +567,85 @@ class AutoStopwatch final
group->releaseStopwatch(iteration_, this);
}
void commitDeltasToGroups(uint64_t userTimeDelta, uint64_t systemTimeDelta,
uint64_t CPOWTimeDelta) const {
applyDeltas(userTimeDelta, systemTimeDelta, CPOWTimeDelta, sharedGroup_);
applyDeltas(userTimeDelta, systemTimeDelta, CPOWTimeDelta, topGroup_);
applyDeltas(userTimeDelta, systemTimeDelta, CPOWTimeDelta, ownGroup_);
// Add recent changes to all the groups owned by this stopwatch.
// Mark the groups as changed recently.
void addToGroups(uint64_t cyclesDelta, uint64_t CPOWTimeDelta) {
addToGroup(cyclesDelta, CPOWTimeDelta, sharedGroup_);
addToGroup(cyclesDelta, CPOWTimeDelta, topGroup_);
addToGroup(cyclesDelta, CPOWTimeDelta, ownGroup_);
}
void applyDeltas(uint64_t userTimeDelta, uint64_t systemTimeDelta,
uint64_t CPOWTimeDelta, PerformanceGroup* group) const {
// Add recent changes to a single group. Mark the group as changed recently.
void addToGroup(uint64_t cyclesDelta, uint64_t CPOWTimeDelta, PerformanceGroup* group) {
if (!group)
return;
group->data.ticks++;
MOZ_ASSERT(group->hasStopwatch(iteration_, this));
uint64_t totalTimeDelta = userTimeDelta + systemTimeDelta;
group->data.totalUserTime += userTimeDelta;
group->data.totalSystemTime += systemTimeDelta;
group->data.totalCPOWTime += CPOWTimeDelta;
// Update an array containing the number of times we have missed
// at least 2^0 successive ms, 2^1 successive ms, ...
// 2^i successive ms.
// Duration of one frame, i.e. 16ms in museconds
size_t i = 0;
uint64_t duration = 1000;
for (i = 0, duration = 1000;
i < ArrayLength(group->data.durations) && duration < totalTimeDelta;
++i, duration *= 2)
{
group->data.durations[i]++;
if (group->recentTicks == 0) {
// First time we meet this group during the tick,
// mark it as needing updates.
JSRuntime* runtime = cx_->runtime();
runtime->stopwatch.addChangedGroup(group);
}
group->recentTicks++;
group->recentCycles += cyclesDelta;
group->recentCPOW += CPOWTimeDelta;
}
// Get the OS-reported time spent in userland/systemland, in
// microseconds. On most platforms, this data is per-thread,
// but on some platforms we need to fall back to per-process.
bool getTimes(JSRuntime* runtime, uint64_t* userTime, uint64_t* systemTime) const {
MOZ_ASSERT(userTime);
MOZ_ASSERT(systemTime);
// Perform a subtraction for a quantity that should be monotonic
// but is not guaranteed to be so.
//
// If `start <= end`, return `end - start`.
// Otherwise, return `0`.
uint64_t getDelta(const uint64_t end, const uint64_t start) const
{
if (start >= end)
return 0;
return end - start;
}
#if defined(XP_MACOSX)
// On MacOS X, to get we per-thread data, we need to
// reach into the kernel.
mach_msg_type_number_t count = THREAD_BASIC_INFO_COUNT;
thread_basic_info_data_t info;
mach_port_t port = mach_thread_self();
kern_return_t err =
thread_info(/* [in] targeted thread*/ port,
/* [in] nature of information*/ THREAD_BASIC_INFO,
/* [out] thread information */ (thread_info_t)&info,
/* [inout] number of items */ &count);
// We do not need ability to communicate with the thread, so
// let's release the port.
mach_port_deallocate(mach_task_self(), port);
if (err != KERN_SUCCESS)
return false;
*userTime = info.user_time.microseconds + info.user_time.seconds * 1000000;
*systemTime = info.system_time.microseconds + info.system_time.seconds * 1000000;
#elif defined(XP_UNIX)
struct rusage rusage;
#if defined(RUSAGE_THREAD)
// Under Linux, we can obtain per-thread statistics
int err = getrusage(RUSAGE_THREAD, &rusage);
// Return the value of the Timestamp Counter, as provided by the CPU.
// 0 on platforms for which we do not have access to a Timestamp Counter.
uint64_t getCycles() const
{
#if defined(MOZ_HAVE_RDTSC)
return ReadTimestampCounter();
#else
// Under other Unices, we need to do with more noisy
// per-process statistics.
int err = getrusage(RUSAGE_SELF, &rusage);
#endif // defined(RUSAGE_THREAD)
if (err)
return false;
*userTime = rusage.ru_utime.tv_usec + rusage.ru_utime.tv_sec * 1000000;
*systemTime = rusage.ru_stime.tv_usec + rusage.ru_stime.tv_sec * 1000000;
#elif defined(XP_WIN)
// Under Windows, we can obtain per-thread statistics,
// although experience seems to suggest that they are
// not very good under Windows XP.
FILETIME creationFileTime; // Ignored
FILETIME exitFileTime; // Ignored
FILETIME kernelFileTime;
FILETIME userFileTime;
BOOL success = GetThreadTimes(GetCurrentThread(),
&creationFileTime, &exitFileTime,
&kernelFileTime, &userFileTime);
if (!success)
return false;
ULARGE_INTEGER kernelTimeInt;
ULARGE_INTEGER userTimeInt;
kernelTimeInt.LowPart = kernelFileTime.dwLowDateTime;
kernelTimeInt.HighPart = kernelFileTime.dwHighDateTime;
// Convert 100 ns to 1 us, make sure that the result is monotonic
*systemTime = runtime->stopwatch.systemTimeFix.monotonize(kernelTimeInt.QuadPart / 10);
userTimeInt.LowPart = userFileTime.dwLowDateTime;
userTimeInt.HighPart = userFileTime.dwHighDateTime;
// Convert 100 ns to 1 us, make sure that the result is monotonic
*userTime = runtime->stopwatch.userTimeFix.monotonize(userTimeInt.QuadPart / 10);
#endif // defined(XP_MACOSX) || defined(XP_UNIX) || defined(XP_WIN)
return true;
return 0;
#endif // defined(MOZ_HAVE_RDTSC)
}
private:
// Return the identifier of the current CPU, on platforms for which we have
// access to the current CPU.
cpuid_t inline getCPU() const
{
#if defined(XP_WIN)
PROCESSOR_NUMBER proc;
GetCurrentProcessorNumberEx(&proc);
cpuid_t result(proc.Group, proc.Number);
return result;
#elif defined(XP_LINUX)
return sched_getcpu();
#else
return {};
#endif // defined(XP_WIN) || defined(XP_LINUX)
}
// Compare two CPU identifiers.
bool inline isSameCPU(const cpuid_t& a, const cpuid_t& b) const
{
#if defined(XP_WIN)
return a.group_ == b.group_ && a.number_ == b.number_;
#elif defined(XP_LINUX)
return a == b;
#else
return true;
#endif
}
private:
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER;
};
@ -678,9 +662,9 @@ js::RunScript(JSContext* cx, RunState& state)
{
JS_CHECK_RECURSION(cx, return false);
#if defined(NIGHTLY_BUILD)
#if defined(NIGHTLY_BUILD) && defined(MOZ_HAVE_RDTSC)
js::AutoStopwatch stopwatch(cx);
#endif // defined(NIGHTLY_BUILD)
#endif // defined(NIGHTLY_BUILD) && defined(MOZ_HAVE_RDTSC)
SPSEntryMarker marker(cx->runtime(), state.script());

341
js/src/vm/Runtime.cpp
View File

@ -12,6 +12,15 @@
#include "mozilla/MemoryReporting.h"
#include "mozilla/ThreadLocal.h"
#if defined(XP_MACOSX)
#include <mach/mach.h>
#elif defined(XP_UNIX)
#include <sys/resource.h>
#elif defined(XP_WIN)
#include <processthreadsapi.h>
#include <windows.h>
#endif // defined(XP_MACOSX) || defined(XP_UNIX) || defined(XP_WIN)
#include <locale.h>
#include <string.h>
@ -872,12 +881,299 @@ JS::IsProfilingEnabledForRuntime(JSRuntime* runtime)
return runtime->spsProfiler.enabled();
}
void
js::ResetStopwatches(JSRuntime* rt)
JS_PUBLIC_API(void)
js::FlushPerformanceMonitoring(JSRuntime* runtime)
{
MOZ_ASSERT(rt);
rt->stopwatch.reset();
MOZ_ASSERT(runtime);
return runtime->stopwatch.commit();
}
JS_PUBLIC_API(void)
js::ResetPerformanceMonitoring(JSRuntime* runtime)
{
MOZ_ASSERT(runtime);
return runtime->stopwatch.reset();
}
void
JSRuntime::Stopwatch::reset()
{
// All ongoing measures are dependent on the current iteration#.
// By incrementing it, we mark all data as stale. Stale data will
// be overwritten progressively during the execution.
++iteration_;
touchedGroups.clear();
}
void
JSRuntime::Stopwatch::start()
{
if (!isMonitoringJank_) {
return;
}
if (iteration_ == startedAtIteration_) {
// The stopwatch is already started for this iteration.
return;
}
startedAtIteration_ = iteration_;
if (!getResources(&userTimeStart_, &systemTimeStart_))
return;
}
// Commit the data that has been collected during the iteration
// into the actual `PerformanceData`.
//
// We use the proportion of cycles-spent-in-group over
// cycles-spent-in-toplevel-group as an approximation to allocate
// system (kernel) time and user (CPU) time to each group. Note
// that cycles are not an exact measure:
//
// 1. if the computer has gone to sleep, the clock may be reset to 0;
// 2. if the process is moved between CPUs/cores, it may end up on a CPU
// or core with an unsynchronized clock;
// 3. the mapping between clock cycles and walltime varies with the current
// frequency of the CPU;
// 4. other threads/processes using the same CPU will also increment
// the counter.
//
// ** Effect of 1. (computer going to sleep)
//
// We assume that this will happen very seldom. Since the final numbers
// are bounded by the CPU time and Kernel time reported by `getresources`,
// the effect will be contained to a single iteration of the event loop.
//
// ** Effect of 2. (moving between CPUs/cores)
//
// On platforms that support it, we only measure the number of cycles
// if we start and end execution of a group on the same
// CPU/core. While there is a small window (a few cycles) during which
// the thread can be migrated without us noticing, we expect that this
// will happen rarely enough that this won't affect the statistics
// meaningfully.
//
// On other platforms, assuming that the probability of jumping
// between CPUs/cores during a given (real) cycle is constant, and
// that the distribution of differences between clocks is even, the
// probability that the number of cycles reported by a measure is
// modified by X cycles should be a gaussian distribution, with groups
// with longer execution having a larger amplitude than groups with
// shorter execution. Since we discard measures that result in a
// negative number of cycles, this distribution is actually skewed
// towards over-estimating the number of cycles of groups that already
// have many cycles and under-estimating the number of cycles that
// already have fewer cycles.
//
// Since the final numbers are bounded by the CPU time and Kernel time
// reported by `getresources`, we accept this bias.
//
// ** Effect of 3. (mapping between clock cycles and walltime)
//
// Assuming that this is evenly distributed, we expect that this will
// eventually balance out.
//
// ** Effect of 4. (cycles increase with system activity)
//
// Assuming that, within an iteration of the event loop, this happens
// unformly over time, this will skew towards over-estimating the number
// of cycles of groups that already have many cycles and under-estimating
// the number of cycles that already have fewer cycles.
//
// Since the final numbers are bounded by the CPU time and Kernel time
// reported by `getresources`, we accept this bias.
//
// ** Big picture
//
// Computing the number of cycles is fast and should be accurate
// enough in practice. Alternatives (such as calling `getresources`
// all the time or sampling from another thread) are very expensive
// in system calls and/or battery and not necessarily more accurate.
void
JSRuntime::Stopwatch::commit()
{
#if !defined(MOZ_HAVE_RDTSC)
// The AutoStopwatch is only executed if `MOZ_HAVE_RDTSC`.
return;
#endif // !defined(MOZ_HAVE_RDTSC)
if (!isMonitoringJank_) {
// Either we have not started monitoring or monitoring has
// been cancelled during the iteration.
return;
}
if (startedAtIteration_ != iteration_) {
// No JS code has been monitored during this iteration.
return;
}
uint64_t userTimeStop, systemTimeStop;
if (!getResources(&userTimeStop, &systemTimeStop))
return;
// `getResources` is not guaranteed to be monotonic, so round up
// any negative result to 0 milliseconds.
uint64_t userTimeDelta = 0;
if (userTimeStop > userTimeStart_)
userTimeDelta = userTimeStop - userTimeStart_;
uint64_t systemTimeDelta = 0;
if (systemTimeStop > systemTimeStart_)
systemTimeDelta = systemTimeStop - systemTimeStart_;
mozilla::RefPtr<js::PerformanceGroup> group = performance.getOwnGroup();
const uint64_t totalRecentCycles = group->recentCycles;
mozilla::Vector<mozilla::RefPtr<js::PerformanceGroup>> recentGroups;
touchedGroups.swap(recentGroups);
MOZ_ASSERT(recentGroups.length() > 0);
// We should only reach this stage if `group` has had some activity.
MOZ_ASSERT(group->recentTicks > 0);
for (mozilla::RefPtr<js::PerformanceGroup>* iter = recentGroups.begin(); iter != recentGroups.end(); ++iter) {
transferDeltas(userTimeDelta, systemTimeDelta, totalRecentCycles, *iter);
}
// Make sure that `group` was treated along with the other items of `recentGroups`.
MOZ_ASSERT(group->recentTicks == 0);
// Finally, reset immediately, to make sure that we're not hit by the
// end of a nested event loop (which would cause `commit` to be called
// twice in succession).
reset();
}
void
JSRuntime::Stopwatch::transferDeltas(uint64_t totalUserTimeDelta, uint64_t totalSystemTimeDelta,
uint64_t totalCyclesDelta, js::PerformanceGroup* group) {
const uint64_t ticksDelta = group->recentTicks;
const uint64_t cpowTimeDelta = group->recentCPOW;
const uint64_t cyclesDelta = group->recentCycles;
group->resetRecentData();
// We have now performed all cleanup and may `return` at any time without fear of leaks.
if (group->iteration() != iteration_) {
// Stale data, don't commit.
return;
}
// When we add a group as changed, we immediately set its
// `recentTicks` from 0 to 1. If we have `ticksDelta == 0` at
// this stage, we have already called `resetRecentData` but we
// haven't removed it from the list.
MOZ_ASSERT(ticksDelta != 0);
MOZ_ASSERT(cyclesDelta <= totalCyclesDelta);
if (cyclesDelta == 0 || totalCyclesDelta == 0) {
// Nothing useful, don't commit.
return;
}
double proportion = (double)cyclesDelta / (double)totalCyclesDelta;
MOZ_ASSERT(proportion <= 1);
const uint64_t userTimeDelta = proportion * totalUserTimeDelta;
const uint64_t systemTimeDelta = proportion * totalSystemTimeDelta;
group->data.totalUserTime += userTimeDelta;
group->data.totalSystemTime += systemTimeDelta;
group->data.totalCPOWTime += cpowTimeDelta;
group->data.ticks += ticksDelta;
const uint64_t totalTimeDelta = userTimeDelta + systemTimeDelta;
size_t i = 0;
uint64_t duration = 1000; // 1ms in µs
for (i = 0, duration = 1000;
i < mozilla::ArrayLength(group->data.durations) && duration < totalTimeDelta;
++i, duration *= 2) {
group->data.durations[i]++;
}
}
// Get the OS-reported time spent in userland/systemland, in
// microseconds. On most platforms, this data is per-thread,
// but on some platforms we need to fall back to per-process.
// Data is not guaranteed to be monotonic.
bool
JSRuntime::Stopwatch::getResources(uint64_t* userTime,
uint64_t* systemTime) const {
MOZ_ASSERT(userTime);
MOZ_ASSERT(systemTime);
#if defined(XP_MACOSX)
// On MacOS X, to get we per-thread data, we need to
// reach into the kernel.
mach_msg_type_number_t count = THREAD_BASIC_INFO_COUNT;
thread_basic_info_data_t info;
mach_port_t port = mach_thread_self();
kern_return_t err =
thread_info(/* [in] targeted thread*/ port,
/* [in] nature of information*/ THREAD_BASIC_INFO,
/* [out] thread information */ (thread_info_t)&info,
/* [inout] number of items */ &count);
// We do not need ability to communicate with the thread, so
// let's release the port.
mach_port_deallocate(mach_task_self(), port);
if (err != KERN_SUCCESS)
return false;
*userTime = info.user_time.microseconds + info.user_time.seconds * 1000000;
*systemTime = info.system_time.microseconds + info.system_time.seconds * 1000000;
#elif defined(XP_UNIX)
struct rusage rusage;
#if defined(RUSAGE_THREAD)
// Under Linux, we can obtain per-thread statistics
int err = getrusage(RUSAGE_THREAD, &rusage);
#else
// Under other Unices, we need to do with more noisy
// per-process statistics.
int err = getrusage(RUSAGE_SELF, &rusage);
#endif // defined(RUSAGE_THREAD)
if (err)
return false;
*userTime = rusage.ru_utime.tv_usec + rusage.ru_utime.tv_sec * 1000000;
*systemTime = rusage.ru_stime.tv_usec + rusage.ru_stime.tv_sec * 1000000;
#elif defined(XP_WIN)
// Under Windows, we can obtain per-thread statistics,
// although experience seems to suggest that they are
// not very good under Windows XP.
FILETIME creationFileTime; // Ignored
FILETIME exitFileTime; // Ignored
FILETIME kernelFileTime;
FILETIME userFileTime;
BOOL success = GetThreadTimes(GetCurrentThread(),
&creationFileTime, &exitFileTime,
&kernelFileTime, &userFileTime);
if (!success)
return false;
ULARGE_INTEGER kernelTimeInt;
kernelTimeInt.LowPart = kernelFileTime.dwLowDateTime;
kernelTimeInt.HighPart = kernelFileTime.dwHighDateTime;
// Convert 100 ns to 1 us.
*systemTime = kernelTimeInt.QuadPart / 10;
ULARGE_INTEGER userTimeInt;
userTimeInt.LowPart = userFileTime.dwLowDateTime;
userTimeInt.HighPart = userFileTime.dwHighDateTime;
// Convert 100 ns to 1 us.
*userTime = userTimeInt.QuadPart / 10;
#endif // defined(XP_MACOSX) || defined(XP_UNIX) || defined(XP_WIN)
return true;
}
bool
js::SetStopwatchIsMonitoringJank(JSRuntime* rt, bool value)
@ -961,39 +1257,46 @@ js::PerformanceGroupHolder::getSharedGroup(JSContext* cx)
} else {
sharedGroup_ = runtime_->new_<PerformanceGroup>(cx, key);
if (!sharedGroup_)
return nullptr;
return nullptr;
runtime_->stopwatch.groups().add(ptr, key, sharedGroup_);
}
return sharedGroup_;
}
PerformanceData*
js::GetPerformanceData(JSRuntime* rt)
void
js::AddCPOWPerformanceDelta(JSRuntime* rt, uint64_t delta)
{
return &rt->stopwatch.performance.getOwnGroup()->data;
rt->stopwatch.totalCPOWTime += delta;
}
js::PerformanceGroup::PerformanceGroup(JSRuntime* rt)
: uid(rt->stopwatch.uniqueId()),
recentCycles(0),
recentTicks(0),
recentCPOW(0),
runtime_(rt),
stopwatch_(nullptr),
iteration_(0),
key_(nullptr),
refCount_(0),
isSharedGroup_(false)
{ }
{
}
js::PerformanceGroup::PerformanceGroup(JSContext* cx, void* key)
: uid(cx->runtime()->stopwatch.uniqueId()),
runtime_(cx->runtime()),
stopwatch_(nullptr),
iteration_(0),
key_(key),
refCount_(0),
isSharedGroup_(true)
{ }
js::PerformanceGroup::PerformanceGroup(JSContext* cx, void* key)
: uid(cx->runtime()->stopwatch.uniqueId()),
recentCycles(0),
recentTicks(0),
recentCPOW(0),
runtime_(cx->runtime()),
stopwatch_(nullptr),
iteration_(0),
key_(key),
refCount_(0),
isSharedGroup_(true)
{
}
void
js::PerformanceGroup::AddRef()

174
js/src/vm/Runtime.h
View File

@ -15,6 +15,7 @@
#include "mozilla/Scoped.h"
#include "mozilla/ThreadLocal.h"
#include "mozilla/UniquePtr.h"
#include "mozilla/Vector.h"
#include <setjmp.h>
@ -1517,17 +1518,6 @@ struct JSRuntime : public JS::shadow::Runtime,
*/
js::PerformanceGroupHolder performance;
/**
* The number of times we have entered the event loop.
* Used to reset counters whenever we enter the loop,
* which may be caused either by having completed the
* previous run of the event loop, or by entering a
* nested loop.
*
* Always incremented by 1, may safely overflow.
*/
uint64_t iteration;
/**
* Callback used to ask the embedding to determine in which
* Performance Group the current execution belongs. Typically, this is
@ -1540,31 +1530,56 @@ struct JSRuntime : public JS::shadow::Runtime,
*/
JSCurrentPerfGroupCallback currentPerfGroupCallback;
/**
* The number of the current iteration of the event loop.
*/
uint64_t iteration() {
return iteration_;
}
explicit Stopwatch(JSRuntime* runtime)
: performance(runtime)
, iteration(0)
, currentPerfGroupCallback(nullptr)
, totalCPOWTime(0)
, isMonitoringJank_(false)
, isMonitoringCPOW_(false)
, isMonitoringPerCompartment_(false)
, iteration_(0)
, startedAtIteration_(0)
, idCounter_(0)
{ }
/**
* Reset the stopwatch.
*
* This method is meant to be called whenever we start processing
* an event, to ensure that stop any ongoing measurement that would
* otherwise provide irrelevant results.
* This method is meant to be called whenever we start
* processing an event, to ensure that we stop any ongoing
* measurement that would otherwise provide irrelevant
* results.
*/
void reset() {
++iteration;
}
void reset();
/**
* Start the stopwatch.
*
* This method is meant to be called once we know that the
* current event contains JavaScript code to execute. Calling
* this several times during the same iteration is idempotent.
*/
void start();
/**
* Commit the performance data collected since the last call
* to `start()`, unless `reset()` has been called since then.
*/
void commit();
/**
* Activate/deactivate stopwatch measurement of jank.
*
* Noop if `value` is `true` and the stopwatch is already active,
* or if `value` is `false` and the stopwatch is already inactive.
* Noop if `value` is `true` and the stopwatch is already
* measuring jank, or if `value` is `false` and the stopwatch
* is not measuring jank.
*
* Otherwise, any pending measurements are dropped, but previous
* measurements remain stored.
@ -1587,6 +1602,18 @@ struct JSRuntime : public JS::shadow::Runtime,
return isMonitoringJank_;
}
/**
* Activate/deactivate stopwatch measurement per compartment.
*
* Noop if `value` is `true` and the stopwatch is already
* measuring per compartment, or if `value` is `false` and the
* stopwatch is not measuring per compartment.
*
* Otherwise, any pending measurements are dropped, but previous
* measurements remain stored.
*
* May return `false` if the underlying hashtable cannot be allocated.
*/
bool setIsMonitoringPerCompartment(bool value) {
if (isMonitoringPerCompartment_ != value)
reset();
@ -1605,8 +1632,25 @@ struct JSRuntime : public JS::shadow::Runtime,
/**
* Activate/deactivate stopwatch measurement of CPOW.
*
* Noop if `value` is `true` and the stopwatch is already
* measuring CPOW, or if `value` is `false` and the stopwatch
* is not measuring CPOW.
*
* Otherwise, any pending measurements are dropped, but previous
* measurements remain stored.
*
* May return `false` if the underlying hashtable cannot be allocated.
*/
bool setIsMonitoringCPOW(bool value) {
if (isMonitoringCPOW_ != value)
reset();
if (value && !groups_.initialized()) {
if (!groups_.init(128))
return false;
}
isMonitoringCPOW_ = value;
return true;
}
@ -1622,46 +1666,92 @@ struct JSRuntime : public JS::shadow::Runtime,
return idCounter_++;
}
// Some systems have non-monotonic clocks. While we cannot
// improve the precision, we can make sure that our measures
// are monotonic nevertheless. We do this by storing the
// result of the latest call to the clock and making sure
// that the next timestamp is greater or equal.
struct MonotonicTimeStamp {
MonotonicTimeStamp()
: latestGood_(0)
{}
inline uint64_t monotonize(uint64_t stamp)
{
if (stamp <= latestGood_)
return latestGood_;
latestGood_ = stamp;
return stamp;
}
private:
uint64_t latestGood_;
};
MonotonicTimeStamp systemTimeFix;
MonotonicTimeStamp userTimeFix;
/**
* Mark a group as changed during the current iteration.
*
* Recent data from this group will be post-processed and
* committed at the end of the iteration.
*/
void addChangedGroup(js::PerformanceGroup* group) {
MOZ_ASSERT(group->recentTicks == 0);
touchedGroups.append(group);
}
// The total amount of time spent waiting on CPOWs since the
// start of the process, in microseconds.
uint64_t totalCPOWTime;
private:
Stopwatch(const Stopwatch&) = delete;
Stopwatch& operator=(const Stopwatch&) = delete;
// Commit a piece of data to a single group.
// `totalUserTimeDelta`, `totalSystemTimeDelta`, `totalCyclesDelta`
// represent the outer measures, taken for the entire runtime.
void transferDeltas(uint64_t totalUserTimeDelta,
uint64_t totalSystemTimeDelta,
uint64_t totalCyclesDelta,
js::PerformanceGroup* destination);
// Query the OS for the time spent in CPU/kernel since process
// launch.
bool getResources(uint64_t* userTime, uint64_t* systemTime) const;
private:
Groups groups_;
friend struct js::PerformanceGroupHolder;
/**
* `true` if stopwatch monitoring is active, `false` otherwise.
* `true` if stopwatch monitoring is active for Jank, `false` otherwise.
*/
bool isMonitoringJank_;
/**
* `true` if stopwatch monitoring is active for CPOW, `false` otherwise.
*/
bool isMonitoringCPOW_;
/**
* `true` if the stopwatch should udpdate data per-compartment, in
* addition to data per-group.
*/
bool isMonitoringPerCompartment_;
/**
* The number of times we have entered the event loop.
* Used to reset counters whenever we enter the loop,
* which may be caused either by having completed the
* previous run of the event loop, or by entering a
* nested loop.
*
* Always incremented by 1, may safely overflow.
*/
uint64_t iteration_;
/**
* The iteration at which the stopwatch was last started.
*
* Used both to avoid starting the stopwatch several times
* during the same event loop and to avoid committing stale
* stopwatch results.
*/
uint64_t startedAtIteration_;
/**
* A counter used to generate unique identifiers for groups.
*/
uint64_t idCounter_;
/**
* The timestamps returned by `getResources()` during the call to
* `start()` in the current iteration of the event loop.
*/
uint64_t userTimeStart_;
uint64_t systemTimeStart_;
/**
* Performance groups used during the current event.
*
* They are cleared by `commit()` and `reset()`.
*/
mozilla::Vector<mozilla::RefPtr<js::PerformanceGroup>> touchedGroups;
};
Stopwatch stopwatch;
};

4
js/xpconnect/src/nsXPConnect.cpp
View File

@ -948,6 +948,8 @@ nsXPConnect::OnProcessNextEvent(nsIThreadInternal* aThread, bool aMayWait,
{
MOZ_ASSERT(NS_IsMainThread());
mRuntime->OnBeforeProcessNextEvent();
// If ProcessNextEvent was called during a Promise "then" callback, we
// must process any pending microtasks before blocking in the event loop,
// otherwise we may deadlock until an event enters the queue later.
@ -996,6 +998,8 @@ nsXPConnect::AfterProcessNextEvent(nsIThreadInternal* aThread,
Promise::PerformMicroTaskCheckpoint();
mRuntime->OnAfterMicroTaskCheckPoint();
PopNullJSContext();
return NS_OK;

16
js/xpconnect/src/xpcprivate.h
View File

@ -615,10 +615,24 @@ public:
PRTime GetWatchdogTimestamp(WatchdogTimestampCategory aCategory);
// Called before we start processing the next event on the main
// thread.
void OnBeforeProcessNextEvent() {
// As we may be entering a nested event loop, we need to
// cancel any ongoing performance measurement.
js::ResetPerformanceMonitoring(Get()->Runtime());
}
// Called after we have finished processing the next event,
// including micro-tasks.
void OnAfterMicroTaskCheckPoint() {
// Now that we are certain that the event is complete,
// we can flush any ongoing performance measurement.
js::FlushPerformanceMonitoring(Get()->Runtime());
}
void OnProcessNextEvent() {
mSlowScriptCheckpoint = mozilla::TimeStamp::NowLoRes();
mSlowScriptSecondHalf = false;
js::ResetStopwatches(Get()->Runtime());
}
void OnAfterProcessNextEvent() {
mSlowScriptCheckpoint = mozilla::TimeStamp();

15
toolkit/components/perfmonitoring/tests/xpcshell/test_compartments.js
View File

@ -11,8 +11,8 @@ function run_test() {
}
let promiseStatistics = Task.async(function*(name) {
yield Promise.resolve(); // Make sure that we wait until
// statistics have been updated.
yield new Promise(resolve => do_execute_soon(resolve));
// Make sure that we wait until statistics have been updated.
let service = Cc["@mozilla.org/toolkit/performance-stats-service;1"].
getService(Ci.nsIPerformanceStatsService);
let snapshot = service.getSnapshot();
@ -23,6 +23,7 @@ let promiseStatistics = Task.async(function*(name) {
let normalized = JSON.parse(JSON.stringify(data));
componentsData.push(data);
}
yield new Promise(resolve => do_execute_soon(resolve));
return {
processData: JSON.parse(JSON.stringify(snapshot.getProcessData())),
componentsData
@ -34,14 +35,14 @@ let promiseSetMonitoring = Task.async(function*(to) {
getService(Ci.nsIPerformanceStatsService);
service.isMonitoringJank = to;
service.isMonitoringCPOW = to;
yield Promise.resolve();
yield new Promise(resolve => do_execute_soon(resolve));
});
let promiseSetPerCompartment = Task.async(function*(to) {
let service = Cc["@mozilla.org/toolkit/performance-stats-service;1"].
getService(Ci.nsIPerformanceStatsService);
service.isMonitoringPerCompartment = to;
yield Promise.resolve();
yield new Promise(resolve => do_execute_soon(resolve));
});
function getBuiltinStatistics(name, snapshot) {
@ -63,7 +64,7 @@ function burnCPU(ms) {
ignored.shift();
++counter;
}
do_print("Burning CPU over, after " + counter + " iterations");
do_print(`Burning CPU over, after ${counter} iterations and ${Date.now() - start} milliseconds.`);
}
function ensureEquals(snap1, snap2, name) {
@ -133,6 +134,7 @@ add_task(function* test_measure() {
if (skipPrecisionTests) {
do_print("Skipping totalUserTime check under Windows XP, as timer is not always updated by the OS.")
} else {
do_print(JSON.stringify(process2));
Assert.ok(process2.totalUserTime - process1.totalUserTime >= 10000, `At least 10ms counted for process time (${process2.totalUserTime - process1.totalUserTime})`);
}
Assert.equal(process2.totalCPOWTime, process1.totalCPOWTime, "We haven't used any CPOW time during the first burn");
@ -162,8 +164,9 @@ add_task(function* test_measure() {
for (let stats of [stats1, stats2, stats3, stats4]) {
Assert.ok(!stats.componentsData.find(x => x.name.includes("Task.jsm")), "At this stage, Task.jsm doesn't show up in the components data");
}
yield promiseSetMonitoring(true);
yield promiseSetPerCompartment(true);
burnCPU(300);
let stats5 = yield promiseStatistics("With per-compartment monitoring");
Assert.ok(stats5.componentsData.find(x => x.name.includes("Task.jsm")), "With per-compartment monitoring, test_compartments.js shows up");
Assert.ok(stats5.componentsData.find(x => x.name.indexOf("Task.jsm") != -1), "With per-compartment monitoring, Task.jsm shows up");
});