From 456449f25a825b95330f01aa5ec3d25e5e27bafe Mon Sep 17 00:00:00 2001 From: Steve Fink Date: Thu, 13 Nov 2014 12:23:26 -0800 Subject: [PATCH] Bug 1088831 - Account for the storebuffer compaction time, r=jonco --HG-- extra : rebase_source : f193ff3774353572c48814f8fd2669d91feb4745 --- js/src/gc/Statistics.cpp | 25 ++++++++++++++++++++----- js/src/gc/Statistics.h | 9 +++++++++ js/src/gc/StoreBuffer.cpp | 21 +++++++++++++-------- js/src/gc/StoreBuffer.h | 2 +- js/src/gc/Verifier.cpp | 5 ++++- js/src/jsgc.cpp | 2 ++ 6 files changed, 49 insertions(+), 15 deletions(-) diff --git a/js/src/gc/Statistics.cpp b/js/src/gc/Statistics.cpp index 9624251b986..5c415c03b87 100644 --- a/js/src/gc/Statistics.cpp +++ b/js/src/gc/Statistics.cpp @@ -326,6 +326,9 @@ static const PhaseInfo phases[] = { { PHASE_COMPACT_UPDATE, "Compact Update", PHASE_COMPACT, }, { PHASE_COMPACT_UPDATE_GRAY, "Compact Update Gray", PHASE_COMPACT_UPDATE, }, { PHASE_GC_END, "End Callback", PHASE_NO_PARENT }, + { PHASE_MINOR_GC, "Minor GC", PHASE_NO_PARENT }, + { PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC, "Compact Store Buffers", PHASE_MINOR_GC }, + { PHASE_COMPACT_STOREBUFFER_NO_PARENT, "Compact Store Buffers (toplevel)", PHASE_NO_PARENT }, { PHASE_LIMIT, nullptr, PHASE_NO_PARENT } }; @@ -386,6 +389,7 @@ Statistics::formatData(StatisticsSerializer &ss, uint64_t timestamp) ss.appendNumber("Total Compartments", "%d", "", zoneStats.compartmentCount); ss.appendNumber("Minor GCs", "%d", "", counts[STAT_MINOR_GC]); ss.appendNumber("Store Buffer Compactions", "%d", "", counts[STAT_COMPACT_STOREBUFFER]); + ss.appendNumber("Store Buffer Overflows", "%d", "", counts[STAT_STOREBUFFER_OVERFLOW]); ss.appendNumber("MMU (20ms)", "%d", "%", int(mmu20 * 100)); ss.appendNumber("MMU (50ms)", "%d", "%", int(mmu50 * 100)); ss.appendDecimal("SCC Sweep Total", "ms", t(sccTotal)); @@ -478,6 +482,7 @@ Statistics::formatDescription() Compartments Collected: %d of %d\n\ MinorGCs since last GC: %d\n\ Store Buffer Compactions: %d\n\ + Store Buffer Overflows: %d\n\ MMU 20ms:%.1f%%; 50ms:%.1f%%\n\ SCC Sweep Total (MaxPause): %.3fms (%.3fms)\n\ HeapSize: %.3f MiB\n\ @@ -494,6 +499,7 @@ Statistics::formatDescription() zoneStats.collectedCompartmentCount, zoneStats.compartmentCount, counts[STAT_MINOR_GC], counts[STAT_COMPACT_STOREBUFFER], + counts[STAT_STOREBUFFER_OVERFLOW], mmu20 * 100., mmu50 * 100., t(sccTotal), t(sccLongest), double(preBytes) / 1024. / 1024., @@ -643,6 +649,8 @@ Statistics::Statistics(JSRuntime *rt) { PodArrayZero(phaseTotals); PodArrayZero(counts); + PodArrayZero(phaseStartTimes); + PodArrayZero(phaseTimes); char *env = getenv("MOZ_GCTIMER"); if (!env || strcmp(env, "none") == 0) { @@ -726,9 +734,6 @@ Statistics::printStats() void Statistics::beginGC(JSGCInvocationKind kind) { - PodArrayZero(phaseStartTimes); - PodArrayZero(phaseTimes); - slices.clearAndFree(); sccTimes.clearAndFree(); gckind = kind; @@ -770,6 +775,11 @@ Statistics::endGC() if (fp) printStats(); + + // Clear the timers at the end of a GC because we accumulate time for some + // phases (eg storebuffer compaction) during the mutator's run. + PodArrayZero(phaseStartTimes); + PodArrayZero(phaseTimes); } void @@ -837,6 +847,9 @@ Statistics::beginPhase(Phase phase) Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT; MOZ_ASSERT(phaseNestingDepth < MAX_NESTING); MOZ_ASSERT_IF(gcDepth == 1, phases[phase].parent == parent); + MOZ_ASSERT_IF(phase == PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC, parent == PHASE_MINOR_GC); + MOZ_ASSERT_IF(phase == PHASE_COMPACT_STOREBUFFER_NO_PARENT, parent == PHASE_NO_PARENT); + phaseNesting[phaseNestingDepth] = phase; phaseNestingDepth++; #endif @@ -849,8 +862,10 @@ Statistics::endPhase(Phase phase) { phaseNestingDepth--; - int64_t t = PRMJ_Now() - phaseStartTimes[phase]; - slices.back().phaseTimes[phase] += t; + int64_t now = PRMJ_Now(); + int64_t t = now - phaseStartTimes[phase]; + if (!slices.empty()) + slices.back().phaseTimes[phase] += t; phaseTimes[phase] += t; phaseStartTimes[phase] = 0; } diff --git a/js/src/gc/Statistics.h b/js/src/gc/Statistics.h index 88c7b338ee9..6793d024f61 100644 --- a/js/src/gc/Statistics.h +++ b/js/src/gc/Statistics.h @@ -70,6 +70,9 @@ enum Phase { PHASE_COMPACT_UPDATE, PHASE_COMPACT_UPDATE_GRAY, PHASE_GC_END, + PHASE_MINOR_GC, + PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC, + PHASE_COMPACT_STOREBUFFER_NO_PARENT, PHASE_LIMIT }; @@ -78,8 +81,14 @@ enum Stat { STAT_NEW_CHUNK, STAT_DESTROY_CHUNK, STAT_MINOR_GC, + + // Number of times the storebuffers were compacted STAT_COMPACT_STOREBUFFER, + // Number of times a 'put' into a storebuffer overflowed, triggering a + // compaction + STAT_STOREBUFFER_OVERFLOW, + STAT_LIMIT }; diff --git a/js/src/gc/StoreBuffer.cpp b/js/src/gc/StoreBuffer.cpp index c9bb351897f..4462549b115 100644 --- a/js/src/gc/StoreBuffer.cpp +++ b/js/src/gc/StoreBuffer.cpp @@ -99,6 +99,8 @@ StoreBuffer::MonoTypeBuffer::handleOverflow(StoreBuffer *owner) * Compact the buffer now, and if that fails to free enough space then * trigger a minor collection. */ + gcstats::AutoPhase ap(owner->stats(), PHASE_COMPACT_STOREBUFFER_NO_PARENT); + owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW); compact(owner); if (isLowOnSpace()) owner->setAboutToOverflow(); @@ -107,8 +109,10 @@ StoreBuffer::MonoTypeBuffer::handleOverflow(StoreBuffer *owner) * A minor GC has already been triggered, so there's no point * compacting unless the buffer is totally full. */ - if (storage_->availableInCurrentChunk() < sizeof(T)) - maybeCompact(owner); + if (storage_->availableInCurrentChunk() < sizeof(T)) { + owner->stats().count(gcstats::STAT_STOREBUFFER_OVERFLOW); + maybeCompact(owner, PHASE_COMPACT_STOREBUFFER_NO_PARENT); + } } } @@ -116,8 +120,6 @@ template void StoreBuffer::MonoTypeBuffer::compactRemoveDuplicates(StoreBuffer *owner) { - Statistics& stats = owner->stats(); - typedef HashSet DedupSet; DedupSet duplicates; @@ -138,7 +140,7 @@ StoreBuffer::MonoTypeBuffer::compactRemoveDuplicates(StoreBuffer *owner) storage_->release(insert.mark()); duplicates.clear(); - stats.count(gcstats::STAT_COMPACT_STOREBUFFER); + owner->stats().count(gcstats::STAT_COMPACT_STOREBUFFER); } template @@ -152,11 +154,13 @@ StoreBuffer::MonoTypeBuffer::compact(StoreBuffer *owner) template void -StoreBuffer::MonoTypeBuffer::maybeCompact(StoreBuffer *owner) +StoreBuffer::MonoTypeBuffer::maybeCompact(StoreBuffer *owner, gcstats::Phase phase) { MOZ_ASSERT(storage_); - if (storage_->used() != usedAtLastCompact_) + if (storage_->used() != usedAtLastCompact_) { + gcstats::AutoPhase ap(owner->stats(), phase); compact(owner); + } } template @@ -168,7 +172,8 @@ StoreBuffer::MonoTypeBuffer::mark(StoreBuffer *owner, JSTracer *trc) if (!storage_) return; - maybeCompact(owner); + maybeCompact(owner, PHASE_COMPACT_STOREBUFFER_IN_MINOR_GC); + for (LifoAlloc::Enum e(*storage_); !e.empty(); e.popFront()) { T *edge = e.get(); edge->mark(trc); diff --git a/js/src/gc/StoreBuffer.h b/js/src/gc/StoreBuffer.h index 2a1458c71dc..94e4b88e713 100644 --- a/js/src/gc/StoreBuffer.h +++ b/js/src/gc/StoreBuffer.h @@ -144,7 +144,7 @@ class StoreBuffer virtual void compact(StoreBuffer *owner); /* Compacts if any entries have been added since the last compaction. */ - void maybeCompact(StoreBuffer *owner); + void maybeCompact(StoreBuffer *owner, gcstats::Phase phase); /* Add one item to the buffer. */ void put(StoreBuffer *owner, const T &t) { diff --git a/js/src/gc/Verifier.cpp b/js/src/gc/Verifier.cpp index f092b5e116a..0428252db9b 100644 --- a/js/src/gc/Verifier.cpp +++ b/js/src/gc/Verifier.cpp @@ -503,7 +503,10 @@ js::gc::GCRuntime::endVerifyPostBarriers() if (!edges.init()) goto oom; trc->edges = &edges; - storeBuffer.markAll(trc); + { + gcstats::AutoPhase ap(stats, gcstats::PHASE_MINOR_GC); + storeBuffer.markAll(trc); + } /* Walk the heap to find any edges not the the |edges| set. */ trc->setTraceCallback(PostVerifierVisitEdge); diff --git a/js/src/jsgc.cpp b/js/src/jsgc.cpp index 5a73bf861ba..06269c0ea30 100644 --- a/js/src/jsgc.cpp +++ b/js/src/jsgc.cpp @@ -6235,6 +6235,7 @@ void GCRuntime::minorGC(JS::gcreason::Reason reason) { #ifdef JSGC_GENERATIONAL + gcstats::AutoPhase ap(stats, gcstats::PHASE_MINOR_GC); minorGCRequested = false; TraceLogger *logger = TraceLoggerForMainThread(rt); AutoTraceLog logMinorGC(logger, TraceLogger::MinorGC); @@ -6249,6 +6250,7 @@ GCRuntime::minorGC(JSContext *cx, JS::gcreason::Reason reason) // Alternate to the runtime-taking form above which allows marking type // objects as needing pretenuring. #ifdef JSGC_GENERATIONAL + gcstats::AutoPhase ap(stats, gcstats::PHASE_MINOR_GC); minorGCRequested = false; TraceLogger *logger = TraceLoggerForMainThread(rt); AutoTraceLog logMinorGC(logger, TraceLogger::MinorGC);