mirror of
https://github.com/mozilla/gecko-dev.git
synced 2024-10-14 13:55:43 +00:00
Bug 1088831 - Track mutator vs GC time in specified intervals, r=jonco
--HG-- extra : rebase_source : 44313ac31315dbebde12bd76ade8f0cfb4d7ce5a
This commit is contained in:
parent
349f11bd1e
commit
256d393e6f
@ -27,6 +27,7 @@ using namespace js::gc;
|
|||||||
using namespace js::gcstats;
|
using namespace js::gcstats;
|
||||||
|
|
||||||
using mozilla::PodArrayZero;
|
using mozilla::PodArrayZero;
|
||||||
|
using mozilla::PodZero;
|
||||||
|
|
||||||
/* Except for the first and last, slices of less than 10ms are not reported. */
|
/* Except for the first and last, slices of less than 10ms are not reported. */
|
||||||
static const int64_t SLICE_MIN_REPORT_TIME = 10 * PRMJ_USEC_PER_MSEC;
|
static const int64_t SLICE_MIN_REPORT_TIME = 10 * PRMJ_USEC_PER_MSEC;
|
||||||
@ -283,6 +284,7 @@ struct PhaseInfo
|
|||||||
static const Phase PHASE_NO_PARENT = PHASE_LIMIT;
|
static const Phase PHASE_NO_PARENT = PHASE_LIMIT;
|
||||||
|
|
||||||
static const PhaseInfo phases[] = {
|
static const PhaseInfo phases[] = {
|
||||||
|
{ PHASE_MUTATOR, "Mutator Running", PHASE_NO_PARENT },
|
||||||
{ PHASE_GC_BEGIN, "Begin Callback", PHASE_NO_PARENT },
|
{ PHASE_GC_BEGIN, "Begin Callback", PHASE_NO_PARENT },
|
||||||
{ PHASE_WAIT_BACKGROUND_THREAD, "Wait Background Thread", PHASE_NO_PARENT },
|
{ PHASE_WAIT_BACKGROUND_THREAD, "Wait Background Thread", PHASE_NO_PARENT },
|
||||||
{ PHASE_MARK_DISCARD_CODE, "Mark Discard Code", PHASE_NO_PARENT },
|
{ PHASE_MARK_DISCARD_CODE, "Mark Discard Code", PHASE_NO_PARENT },
|
||||||
@ -642,6 +644,8 @@ Statistics::Statistics(JSRuntime *rt)
|
|||||||
fullFormat(false),
|
fullFormat(false),
|
||||||
gcDepth(0),
|
gcDepth(0),
|
||||||
nonincrementalReason(nullptr),
|
nonincrementalReason(nullptr),
|
||||||
|
timingMutator(false),
|
||||||
|
timedGCStart(0),
|
||||||
preBytes(0),
|
preBytes(0),
|
||||||
maxPauseInInterval(0),
|
maxPauseInInterval(0),
|
||||||
phaseNestingDepth(0),
|
phaseNestingDepth(0),
|
||||||
@ -778,8 +782,8 @@ Statistics::endGC()
|
|||||||
|
|
||||||
// Clear the timers at the end of a GC because we accumulate time for some
|
// Clear the timers at the end of a GC because we accumulate time for some
|
||||||
// phases (eg storebuffer compaction) during the mutator's run.
|
// phases (eg storebuffer compaction) during the mutator's run.
|
||||||
PodArrayZero(phaseStartTimes);
|
PodZero(&phaseStartTimes[PHASE_GC_BEGIN], PHASE_LIMIT - PHASE_GC_BEGIN);
|
||||||
PodArrayZero(phaseTimes);
|
PodZero(&phaseTimes[PHASE_GC_BEGIN], PHASE_LIMIT - PHASE_GC_BEGIN);
|
||||||
}
|
}
|
||||||
|
|
||||||
void
|
void
|
||||||
@ -836,12 +840,50 @@ Statistics::endSlice()
|
|||||||
PodArrayZero(counts);
|
PodArrayZero(counts);
|
||||||
}
|
}
|
||||||
|
|
||||||
|
void
|
||||||
|
Statistics::startTimingMutator()
|
||||||
|
{
|
||||||
|
MOZ_ASSERT(!timingMutator);
|
||||||
|
|
||||||
|
// Should only be called from outside of GC
|
||||||
|
MOZ_ASSERT(phaseNestingDepth == 0);
|
||||||
|
|
||||||
|
timingMutator = true;
|
||||||
|
timedGCTime = 0;
|
||||||
|
phaseStartTimes[PHASE_MUTATOR] = 0;
|
||||||
|
phaseTimes[PHASE_MUTATOR] = 0;
|
||||||
|
timedGCStart = 0;
|
||||||
|
|
||||||
|
beginPhase(PHASE_MUTATOR);
|
||||||
|
}
|
||||||
|
|
||||||
|
void
|
||||||
|
Statistics::stopTimingMutator(double &mutator_ms, double &gc_ms)
|
||||||
|
{
|
||||||
|
MOZ_ASSERT(timingMutator);
|
||||||
|
|
||||||
|
// Should only be called from outside of GC
|
||||||
|
MOZ_ASSERT(phaseNestingDepth == 1 && phaseNesting[0] == PHASE_MUTATOR);
|
||||||
|
|
||||||
|
endPhase(PHASE_MUTATOR);
|
||||||
|
mutator_ms = t(phaseTimes[PHASE_MUTATOR]);
|
||||||
|
gc_ms = t(timedGCTime);
|
||||||
|
timingMutator = false;
|
||||||
|
}
|
||||||
|
|
||||||
void
|
void
|
||||||
Statistics::beginPhase(Phase phase)
|
Statistics::beginPhase(Phase phase)
|
||||||
{
|
{
|
||||||
/* Guard against re-entry */
|
/* Guard against re-entry */
|
||||||
MOZ_ASSERT(!phaseStartTimes[phase]);
|
MOZ_ASSERT(!phaseStartTimes[phase]);
|
||||||
|
|
||||||
|
if (timingMutator) {
|
||||||
|
if (phaseNestingDepth == 1 && phaseNesting[0] == PHASE_MUTATOR) {
|
||||||
|
endPhase(PHASE_MUTATOR);
|
||||||
|
timedGCStart = PRMJ_Now();
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
#ifdef DEBUG
|
#ifdef DEBUG
|
||||||
MOZ_ASSERT(phases[phase].index == phase);
|
MOZ_ASSERT(phases[phase].index == phase);
|
||||||
Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT;
|
Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT;
|
||||||
@ -868,6 +910,13 @@ Statistics::endPhase(Phase phase)
|
|||||||
slices.back().phaseTimes[phase] += t;
|
slices.back().phaseTimes[phase] += t;
|
||||||
phaseTimes[phase] += t;
|
phaseTimes[phase] += t;
|
||||||
phaseStartTimes[phase] = 0;
|
phaseStartTimes[phase] = 0;
|
||||||
|
|
||||||
|
if (timingMutator) {
|
||||||
|
if (phaseNestingDepth == 0 && phase != PHASE_MUTATOR) {
|
||||||
|
timedGCTime += now - timedGCStart;
|
||||||
|
beginPhase(PHASE_MUTATOR);
|
||||||
|
}
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
void
|
void
|
||||||
|
@ -27,6 +27,7 @@ class GCParallelTask;
|
|||||||
namespace gcstats {
|
namespace gcstats {
|
||||||
|
|
||||||
enum Phase {
|
enum Phase {
|
||||||
|
PHASE_MUTATOR,
|
||||||
PHASE_GC_BEGIN,
|
PHASE_GC_BEGIN,
|
||||||
PHASE_WAIT_BACKGROUND_THREAD,
|
PHASE_WAIT_BACKGROUND_THREAD,
|
||||||
PHASE_MARK_DISCARD_CODE,
|
PHASE_MARK_DISCARD_CODE,
|
||||||
@ -128,6 +129,9 @@ struct Statistics
|
|||||||
JS::gcreason::Reason reason);
|
JS::gcreason::Reason reason);
|
||||||
void endSlice();
|
void endSlice();
|
||||||
|
|
||||||
|
void startTimingMutator();
|
||||||
|
void stopTimingMutator(double &mutator_ms, double &gc_ms);
|
||||||
|
|
||||||
void reset(const char *reason) { slices.back().resetReason = reason; }
|
void reset(const char *reason) { slices.back().resetReason = reason; }
|
||||||
void nonincremental(const char *reason) { nonincrementalReason = reason; }
|
void nonincremental(const char *reason) { nonincrementalReason = reason; }
|
||||||
|
|
||||||
@ -189,6 +193,13 @@ struct Statistics
|
|||||||
/* Most recent time when the given phase started. */
|
/* Most recent time when the given phase started. */
|
||||||
int64_t phaseStartTimes[PHASE_LIMIT];
|
int64_t phaseStartTimes[PHASE_LIMIT];
|
||||||
|
|
||||||
|
/* Are we currently timing mutator vs GC time? */
|
||||||
|
bool timingMutator;
|
||||||
|
|
||||||
|
/* Bookkeeping for GC timings when timingMutator is true */
|
||||||
|
int64_t timedGCStart;
|
||||||
|
int64_t timedGCTime;
|
||||||
|
|
||||||
/* Total time in a given phase for this GC. */
|
/* Total time in a given phase for this GC. */
|
||||||
int64_t phaseTimes[PHASE_LIMIT];
|
int64_t phaseTimes[PHASE_LIMIT];
|
||||||
|
|
||||||
@ -204,12 +215,10 @@ struct Statistics
|
|||||||
/* Records the maximum GC pause in an API-controlled interval (in us). */
|
/* Records the maximum GC pause in an API-controlled interval (in us). */
|
||||||
int64_t maxPauseInInterval;
|
int64_t maxPauseInInterval;
|
||||||
|
|
||||||
#ifdef DEBUG
|
|
||||||
/* Phases that are currently on stack. */
|
/* Phases that are currently on stack. */
|
||||||
static const size_t MAX_NESTING = 8;
|
static const size_t MAX_NESTING = 8;
|
||||||
Phase phaseNesting[MAX_NESTING];
|
Phase phaseNesting[MAX_NESTING];
|
||||||
#endif
|
size_t phaseNestingDepth;
|
||||||
mozilla::DebugOnly<size_t> phaseNestingDepth;
|
|
||||||
|
|
||||||
/* Sweep times for SCCs of compartments. */
|
/* Sweep times for SCCs of compartments. */
|
||||||
Vector<int64_t, 0, SystemAllocPolicy> sccTimes;
|
Vector<int64_t, 0, SystemAllocPolicy> sccTimes;
|
||||||
|
@ -10,6 +10,7 @@
|
|||||||
|
|
||||||
#include "mozilla/Assertions.h"
|
#include "mozilla/Assertions.h"
|
||||||
|
|
||||||
|
#include "gc/Statistics.h"
|
||||||
#include "vm/ArgumentsObject.h"
|
#include "vm/ArgumentsObject.h"
|
||||||
#include "vm/ForkJoin.h"
|
#include "vm/ForkJoin.h"
|
||||||
|
|
||||||
@ -99,7 +100,7 @@ StoreBuffer::MonoTypeBuffer<T>::handleOverflow(StoreBuffer *owner)
|
|||||||
* Compact the buffer now, and if that fails to free enough space then
|
* Compact the buffer now, and if that fails to free enough space then
|
||||||
* trigger a minor collection.
|
* trigger a minor collection.
|
||||||
*/
|
*/
|
||||||
gcstats::AutoPhase ap(owner->stats(), PHASE_COMPACT_STOREBUFFER_NO_PARENT);
|
gcstats::AutoPhase ap(owner->stats(), gcstats::PHASE_COMPACT_STOREBUFFER_NO_PARENT);
|
||||||
owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW);
|
owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW);
|
||||||
compact(owner);
|
compact(owner);
|
||||||
if (isLowOnSpace())
|
if (isLowOnSpace())
|
||||||
@ -111,7 +112,7 @@ StoreBuffer::MonoTypeBuffer<T>::handleOverflow(StoreBuffer *owner)
|
|||||||
*/
|
*/
|
||||||
if (storage_->availableInCurrentChunk() < sizeof(T)) {
|
if (storage_->availableInCurrentChunk() < sizeof(T)) {
|
||||||
owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW);
|
owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW);
|
||||||
maybeCompact(owner, PHASE_COMPACT_STOREBUFFER_NO_PARENT);
|
maybeCompact(owner, gcstats::PHASE_COMPACT_STOREBUFFER_NO_PARENT);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@ -154,11 +155,11 @@ StoreBuffer::MonoTypeBuffer<T>::compact(StoreBuffer *owner)
|
|||||||
|
|
||||||
template <typename T>
|
template <typename T>
|
||||||
void
|
void
|
||||||
StoreBuffer::MonoTypeBuffer<T>::maybeCompact(StoreBuffer *owner, gcstats::Phase phase)
|
StoreBuffer::MonoTypeBuffer<T>::maybeCompact(StoreBuffer *owner, int phase)
|
||||||
{
|
{
|
||||||
MOZ_ASSERT(storage_);
|
MOZ_ASSERT(storage_);
|
||||||
if (storage_->used() != usedAtLastCompact_) {
|
if (storage_->used() != usedAtLastCompact_) {
|
||||||
gcstats::AutoPhase ap(owner->stats(), phase);
|
gcstats::AutoPhase ap(owner->stats(), static_cast<gcstats::Phase>(phase));
|
||||||
compact(owner);
|
compact(owner);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@ -172,7 +173,7 @@ StoreBuffer::MonoTypeBuffer<T>::mark(StoreBuffer *owner, JSTracer *trc)
|
|||||||
if (!storage_)
|
if (!storage_)
|
||||||
return;
|
return;
|
||||||
|
|
||||||
maybeCompact(owner, PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC);
|
maybeCompact(owner, gcstats::PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC);
|
||||||
|
|
||||||
for (LifoAlloc::Enum e(*storage_); !e.empty(); e.popFront<T>()) {
|
for (LifoAlloc::Enum e(*storage_); !e.empty(); e.popFront<T>()) {
|
||||||
T *edge = e.get<T>();
|
T *edge = e.get<T>();
|
||||||
|
@ -144,7 +144,7 @@ class StoreBuffer
|
|||||||
virtual void compact(StoreBuffer *owner);
|
virtual void compact(StoreBuffer *owner);
|
||||||
|
|
||||||
/* Compacts if any entries have been added since the last compaction. */
|
/* Compacts if any entries have been added since the last compaction. */
|
||||||
void maybeCompact(StoreBuffer *owner, gcstats::Phase phase);
|
void maybeCompact(StoreBuffer *owner, int phase);
|
||||||
|
|
||||||
/* Add one item to the buffer. */
|
/* Add one item to the buffer. */
|
||||||
void put(StoreBuffer *owner, const T &t) {
|
void put(StoreBuffer *owner, const T &t) {
|
||||||
|
@ -1660,6 +1660,43 @@ Quit(JSContext *cx, unsigned argc, jsval *vp)
|
|||||||
return false;
|
return false;
|
||||||
}
|
}
|
||||||
|
|
||||||
|
static bool
|
||||||
|
StartTimingMutator(JSContext *cx, unsigned argc, jsval *vp)
|
||||||
|
{
|
||||||
|
CallArgs args = CallArgsFromVp(argc, vp);
|
||||||
|
if (args.length() > 0) {
|
||||||
|
JS_ReportErrorNumber(cx, my_GetErrorMessage, nullptr,
|
||||||
|
JSSMSG_TOO_MANY_ARGS, "startTimingMutator");
|
||||||
|
return false;
|
||||||
|
}
|
||||||
|
|
||||||
|
cx->runtime()->gc.stats.startTimingMutator();
|
||||||
|
args.rval().setUndefined();
|
||||||
|
return true;
|
||||||
|
}
|
||||||
|
|
||||||
|
static bool
|
||||||
|
StopTimingMutator(JSContext *cx, unsigned argc, jsval *vp)
|
||||||
|
{
|
||||||
|
CallArgs args = CallArgsFromVp(argc, vp);
|
||||||
|
if (args.length() > 0) {
|
||||||
|
JS_ReportErrorNumber(cx, my_GetErrorMessage, nullptr,
|
||||||
|
JSSMSG_TOO_MANY_ARGS, "stopTimingMutator");
|
||||||
|
return false;
|
||||||
|
}
|
||||||
|
|
||||||
|
double mutator_ms, gc_ms;
|
||||||
|
cx->runtime()->gc.stats.stopTimingMutator(mutator_ms, gc_ms);
|
||||||
|
double total_ms = mutator_ms + gc_ms;
|
||||||
|
if (total_ms > 0) {
|
||||||
|
fprintf(gOutFile, "Mutator: %.3fms (%.1f%%), GC: %.3fms (%.1f%%)\n",
|
||||||
|
mutator_ms, mutator_ms / total_ms * 100.0, gc_ms, gc_ms / total_ms * 100.0);
|
||||||
|
}
|
||||||
|
|
||||||
|
args.rval().setUndefined();
|
||||||
|
return true;
|
||||||
|
}
|
||||||
|
|
||||||
static const char *
|
static const char *
|
||||||
ToSource(JSContext *cx, MutableHandleValue vp, JSAutoByteString *bytes)
|
ToSource(JSContext *cx, MutableHandleValue vp, JSAutoByteString *bytes)
|
||||||
{
|
{
|
||||||
@ -4458,6 +4495,14 @@ static const JSFunctionSpecWithHelp shell_functions[] = {
|
|||||||
" Throw if the first two arguments are not the same (both +0 or both -0,\n"
|
" Throw if the first two arguments are not the same (both +0 or both -0,\n"
|
||||||
" both NaN, or non-zero and ===)."),
|
" both NaN, or non-zero and ===)."),
|
||||||
|
|
||||||
|
JS_FN_HELP("startTimingMutator", StartTimingMutator, 0, 0,
|
||||||
|
"startTimingMutator()",
|
||||||
|
" Start accounting time to mutator vs GC."),
|
||||||
|
|
||||||
|
JS_FN_HELP("stopTimingMutator", StopTimingMutator, 0, 0,
|
||||||
|
"stopTimingMutator()",
|
||||||
|
" Stop accounting time to mutator vs GC and dump the results."),
|
||||||
|
|
||||||
JS_FN_HELP("throwError", ThrowError, 0, 0,
|
JS_FN_HELP("throwError", ThrowError, 0, 0,
|
||||||
"throwError()",
|
"throwError()",
|
||||||
" Throw an error from JS_ReportError."),
|
" Throw an error from JS_ReportError."),
|
||||||
|
Loading…
Reference in New Issue
Block a user