Squashed version of several commits to fix the tracelogger. Taken from https://github.com/GNOME/jhbuild/blob/master/patches/mozjs38-fix-tracelogger.patch. # === Fix the SM38 tracelogger === # This patch is a squashed version of several patches that were adapted # to fix failing hunks. # # Applied in the following order, they are: # * https://bugzilla.mozilla.org/show_bug.cgi?id=1223767 # Assertion failure: i < size_, at js/src/vm/TraceLoggingTypes.h:210 # Also fix stop-information to make reduce.py work correctly. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1227914 # Limit the memory tracelogger can take. # This causes tracelogger to flush data to the disk regularly and prevents out of # memory issues if a lot of data gets logged. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1155618 # Fix tracelogger destructor that touches possibly uninitialised hash table. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1223636 # Don't treat extraTextId as containing only extra ids. # This fixes an assertion failure: id == nextTextId at js/src/vm/TraceLoggingGraph.cpp # * https://bugzilla.mozilla.org/show_bug.cgi?id=1227028 # Fix when to keep the payload of a TraceLogger event. # This fixes an assertion failure: textId < uint32_t(1 << 31) at js/src/vm/TraceLoggingGraph.h # * https://bugzilla.mozilla.org/show_bug.cgi?id=1266649 # Handle failing to add to pointermap gracefully. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1280648 # Don't cache based on pointers to movable GC things. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1224123 # Fix the use of LastEntryId in tracelogger.h. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1231170 # Use size in debugger instead of the current id to track last logged item. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1221844 # Move TraceLogger_Invalidation to LOG_ITEM. # Add some debug checks to logTimestamp. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1255766 # Also mark resizing of memory. # * https://bugzilla.mozilla.org/show_bug.cgi?id=1259403 # Only increase capacity by multiples of 2. # Always make sure there are 3 free slots for events. # === diff --git a/js/src/jit-test/tests/tracelogger/bug1231170.js b/js/src/jit-test/tests/tracelogger/bug1231170.js new file mode 100644 index 0000000..023e93e --- /dev/null +++ b/js/src/jit-test/tests/tracelogger/bug1231170.js @@ -0,0 +1,3 @@ +var du = new Debugger(); +if (typeof du.drainTraceLogger === "function") + du.drainTraceLogger(); diff --git a/js/src/jit-test/tests/tracelogger/bug1266649.js b/js/src/jit-test/tests/tracelogger/bug1266649.js new file mode 100644 index 0000000..81ae7ad --- /dev/null +++ b/js/src/jit-test/tests/tracelogger/bug1266649.js @@ -0,0 +1,10 @@ + +var du = new Debugger(); +if (typeof du.setupTraceLogger === "function" && + typeof oomTest === 'function') +{ + du.setupTraceLogger({ + Scripts: true + }) + oomTest(() => function(){}); +} diff --git a/js/src/jit/Ion.cpp b/js/src/jit/Ion.cpp index 93e2fda..09049d6 100644 --- a/js/src/jit/Ion.cpp +++ b/js/src/jit/Ion.cpp @@ -1055,6 +1055,8 @@ IonScript::Destroy(FreeOp* fop, IonScript* script) script->destroyCaches(); script->unlinkFromRuntime(fop); + // Frees the potential event we have set. + script->traceLoggerScriptEvent_ = TraceLoggerEvent(); fop->free_(script); } diff --git a/js/src/vm/Debugger.cpp b/js/src/vm/Debugger.cpp index 26262fd..af7f313 100644 --- a/js/src/vm/Debugger.cpp +++ b/js/src/vm/Debugger.cpp @@ -369,10 +369,10 @@ Debugger::Debugger(JSContext* cx, NativeObject* dbg) objects(cx), environments(cx), #ifdef NIGHTLY_BUILD - traceLoggerLastDrainedId(0), + traceLoggerLastDrainedSize(0), traceLoggerLastDrainedIteration(0), #endif - traceLoggerScriptedCallsLastDrainedId(0), + traceLoggerScriptedCallsLastDrainedSize(0), traceLoggerScriptedCallsLastDrainedIteration(0) { assertSameCompartment(cx, dbg); @@ -3907,9 +3907,9 @@ Debugger::drainTraceLogger(JSContext* cx, unsigned argc, Value* vp) size_t num; TraceLoggerThread* logger = TraceLoggerForMainThread(cx->runtime()); bool lostEvents = logger->lostEvents(dbg->traceLoggerLastDrainedIteration, - dbg->traceLoggerLastDrainedId); + dbg->traceLoggerLastDrainedSize); EventEntry* events = logger->getEventsStartingAt(&dbg->traceLoggerLastDrainedIteration, - &dbg->traceLoggerLastDrainedId, + &dbg->traceLoggerLastDrainedSize, &num); RootedObject array(cx, NewDenseEmptyArray(cx)); @@ -4002,10 +4002,10 @@ Debugger::drainTraceLoggerScriptCalls(JSContext* cx, unsigned argc, Value* vp) size_t num; TraceLoggerThread* logger = TraceLoggerForMainThread(cx->runtime()); bool lostEvents = logger->lostEvents(dbg->traceLoggerScriptedCallsLastDrainedIteration, - dbg->traceLoggerScriptedCallsLastDrainedId); + dbg->traceLoggerScriptedCallsLastDrainedSize); EventEntry* events = logger->getEventsStartingAt( &dbg->traceLoggerScriptedCallsLastDrainedIteration, - &dbg->traceLoggerScriptedCallsLastDrainedId, + &dbg->traceLoggerScriptedCallsLastDrainedSize, &num); RootedObject array(cx, NewDenseEmptyArray(cx)); diff --git a/js/src/vm/Debugger.h b/js/src/vm/Debugger.h index 8cac36a..c92d685 100644 --- a/js/src/vm/Debugger.h +++ b/js/src/vm/Debugger.h @@ -314,10 +314,10 @@ class Debugger : private mozilla::LinkedListElement<Debugger> * lost events. */ #ifdef NIGHTLY_BUILD - uint32_t traceLoggerLastDrainedId; + uint32_t traceLoggerLastDrainedSize; uint32_t traceLoggerLastDrainedIteration; #endif - uint32_t traceLoggerScriptedCallsLastDrainedId; + uint32_t traceLoggerScriptedCallsLastDrainedSize; uint32_t traceLoggerScriptedCallsLastDrainedIteration; class FrameRange; diff --git a/js/src/vm/TraceLogging.cpp b/js/src/vm/TraceLogging.cpp index 6715b36..9766a6f 100644 --- a/js/src/vm/TraceLogging.cpp +++ b/js/src/vm/TraceLogging.cpp @@ -131,7 +131,7 @@ TraceLoggerThread::init() { if (!pointerMap.init()) return false; - if (!extraTextId.init()) + if (!textIdPayloads.init()) return false; if (!events.init()) return false; @@ -185,10 +185,10 @@ TraceLoggerThread::~TraceLoggerThread() graph = nullptr; } - for (TextIdHashMap::Range r = extraTextId.all(); !r.empty(); r.popFront()) - js_delete(r.front().value()); - extraTextId.finish(); - pointerMap.finish(); + if (textIdPayloads.initialized()) { + for (TextIdHashMap::Range r = textIdPayloads.all(); !r.empty(); r.popFront()) + js_delete(r.front().value()); + } } bool @@ -287,7 +287,7 @@ TraceLoggerThread::eventText(uint32_t id) if (id < TraceLogger_Last) return TLTextIdString(static_cast<TraceLoggerTextId>(id)); - TextIdHashMap::Ptr p = extraTextId.lookup(id); + TextIdHashMap::Ptr p = textIdPayloads.lookup(id); MOZ_ASSERT(p); return p->value()->string(); @@ -341,13 +341,15 @@ TraceLoggerThread::extractScriptDetails(uint32_t textId, const char** filename, TraceLoggerEventPayload* TraceLoggerThread::getOrCreateEventPayload(TraceLoggerTextId textId) { - TextIdHashMap::AddPtr p = extraTextId.lookupForAdd(textId); - if (p) + TextIdHashMap::AddPtr p = textIdPayloads.lookupForAdd(textId); + if (p) { + MOZ_ASSERT(p->value()->textId() == textId); // Sanity check. return p->value(); + } TraceLoggerEventPayload* payload = js_new<TraceLoggerEventPayload>(textId, (char*)nullptr); - if (!extraTextId.add(p, textId, payload)) + if (!textIdPayloads.add(p, textId, payload)) return nullptr; return payload; @@ -357,8 +359,10 @@ TraceLoggerEventPayload* TraceLoggerThread::getOrCreateEventPayload(const char* text) { PointerHashMap::AddPtr p = pointerMap.lookupForAdd((const void*)text); - if (p) + if (p) { + MOZ_ASSERT(p->value()->textId() < nextTextId); // Sanity check. return p->value(); + } size_t len = strlen(text); char* str = js_pod_malloc<char>(len + 1); @@ -369,7 +373,7 @@ TraceLoggerThread::getOrCreateEventPayload(const char* text) MOZ_ASSERT(ret == len); MOZ_ASSERT(strlen(str) == len); - uint32_t textId = extraTextId.count() + TraceLogger_Last; + uint32_t textId = nextTextId; TraceLoggerEventPayload* payload = js_new<TraceLoggerEventPayload>(textId, str); if (!payload) { @@ -377,17 +381,19 @@ TraceLoggerThread::getOrCreateEventPayload(const char* text) return nullptr; } - if (!extraTextId.putNew(textId, payload)) { + if (!textIdPayloads.putNew(textId, payload)) { js_delete(payload); return nullptr; } - if (!pointerMap.add(p, text, payload)) - return nullptr; - if (graph.get()) graph->addTextId(textId, str); + nextTextId++; + + if (!pointerMap.add(p, text, payload)) + return nullptr; + return payload; } @@ -407,9 +413,14 @@ TraceLoggerThread::getOrCreateEventPayload(TraceLoggerTextId type, const char* f if (!traceLoggerState->isTextIdEnabled(type)) return getOrCreateEventPayload(type); - PointerHashMap::AddPtr p = pointerMap.lookupForAdd(ptr); - if (p) - return p->value(); + PointerHashMap::AddPtr p; + if (ptr) { + p = pointerMap.lookupForAdd(ptr); + if (p) { + MOZ_ASSERT(p->value()->textId() < nextTextId); // Sanity check. + return p->value(); + } + } // Compute the length of the string to create. size_t lenFilename = strlen(filename); @@ -428,24 +439,28 @@ TraceLoggerThread::getOrCreateEventPayload(TraceLoggerTextId type, const char* f MOZ_ASSERT(ret == len); MOZ_ASSERT(strlen(str) == len); - uint32_t textId = extraTextId.count() + TraceLogger_Last; + uint32_t textId = nextTextId; TraceLoggerEventPayload* payload = js_new<TraceLoggerEventPayload>(textId, str); if (!payload) { js_free(str); return nullptr; } - if (!extraTextId.putNew(textId, payload)) { + if (!textIdPayloads.putNew(textId, payload)) { js_delete(payload); return nullptr; } - if (!pointerMap.add(p, ptr, payload)) - return nullptr; - if (graph.get()) graph->addTextId(textId, str); + nextTextId++; + + if (ptr) { + if (!pointerMap.add(p, ptr, payload)) + return nullptr; + } + return payload; } @@ -453,14 +468,14 @@ TraceLoggerEventPayload* TraceLoggerThread::getOrCreateEventPayload(TraceLoggerTextId type, JSScript* script) { return getOrCreateEventPayload(type, script->filename(), script->lineno(), script->column(), - script); + nullptr); } TraceLoggerEventPayload* TraceLoggerThread::getOrCreateEventPayload(TraceLoggerTextId type, const JS::ReadOnlyCompileOptions& script) { - return getOrCreateEventPayload(type, script.filename(), script.lineno, script.column, &script); + return getOrCreateEventPayload(type, script.filename(), script.lineno, script.column, nullptr); } void @@ -485,7 +500,7 @@ TraceLoggerThread::startEvent(uint32_t id) if (!traceLoggerState->isTextIdEnabled(id)) return; - logTimestamp(id); + log(id); } void @@ -510,7 +525,7 @@ TraceLoggerThread::stopEvent(uint32_t id) if (!traceLoggerState->isTextIdEnabled(id)) return; - logTimestamp(TraceLogger_Stop); + log(TraceLogger_Stop); } void @@ -522,23 +537,57 @@ TraceLoggerThread::logTimestamp(TraceLoggerTextId id) void TraceLoggerThread::logTimestamp(uint32_t id) { + MOZ_ASSERT(id > TraceLogger_LastTreeItem && id < TraceLogger_Last); + log(id); +} + +void +TraceLoggerThread::log(uint32_t id) +{ if (enabled == 0) return; MOZ_ASSERT(traceLoggerState); - if (!events.ensureSpaceBeforeAdd()) { + + // We request for 3 items to add, since if we don't have enough room + // we record the time it took to make more place. To log this information + // we need 2 extra free entries. + if (!events.hasSpaceForAdd(3)) { uint64_t start = rdtsc() - traceLoggerState->startupTime; - if (graph.get()) - graph->log(events); + if (!events.ensureSpaceBeforeAdd(3)) { + if (graph.get()) + graph->log(events); + + iteration_++; + events.clear(); + + // Remove the item in the pointerMap for which the payloads + // have no uses anymore + for (PointerHashMap::Enum e(pointerMap); !e.empty(); e.popFront()) { + if (e.front().value()->uses() != 0) + continue; + + TextIdHashMap::Ptr p = textIdPayloads.lookup(e.front().value()->textId()); + MOZ_ASSERT(p); + textIdPayloads.remove(p); + + e.removeFront(); + } - iteration_++; - events.clear(); + // Free all payloads that have no uses anymore. + for (TextIdHashMap::Enum e(textIdPayloads); !e.empty(); e.popFront()) { + if (e.front().value()->uses() == 0) { + js_delete(e.front().value()); + e.removeFront(); + } + } + } // Log the time it took to flush the events as being from the // Tracelogger. if (graph.get()) { - MOZ_ASSERT(events.capacity() > 2); + MOZ_ASSERT(events.hasSpaceForAdd(2)); EventEntry& entryStart = events.pushUninitialized(); entryStart.time = start; entryStart.textId = TraceLogger_Internal; @@ -548,13 +597,6 @@ TraceLoggerThread::logTimestamp(uint32_t id) entryStop.textId = TraceLogger_Stop; } - // Free all TextEvents that have no uses anymore. - for (TextIdHashMap::Enum e(extraTextId); !e.empty(); e.popFront()) { - if (e.front().value()->uses() == 0) { - js_delete(e.front().value()); - e.removeFront(); - } - } } uint64_t time = rdtsc() - traceLoggerState->startupTime; @@ -956,3 +998,16 @@ TraceLoggerEvent::~TraceLoggerEvent() if (payload_) payload_->release(); } + +TraceLoggerEvent& +TraceLoggerEvent::operator=(const TraceLoggerEvent& other) +{ + if (hasPayload()) + payload()->release(); + if (other.hasPayload()) + other.payload()->use(); + + payload_ = other.payload_; + + return *this; +} diff --git a/js/src/vm/TraceLogging.h b/js/src/vm/TraceLogging.h index a124dcb..91a1eb0 100644 --- a/js/src/vm/TraceLogging.h +++ b/js/src/vm/TraceLogging.h @@ -110,6 +110,9 @@ class TraceLoggerEvent { bool hasPayload() const { return !!payload_; } + + TraceLoggerEvent& operator=(const TraceLoggerEvent& other); + TraceLoggerEvent(const TraceLoggerEvent& event) = delete; }; /** @@ -130,6 +133,10 @@ class TraceLoggerEventPayload { uses_(0) { } + ~TraceLoggerEventPayload() { + MOZ_ASSERT(uses_ == 0); + } + uint32_t textId() { return textId_; } @@ -166,7 +173,8 @@ class TraceLoggerThread mozilla::UniquePtr<TraceLoggerGraph> graph; PointerHashMap pointerMap; - TextIdHashMap extraTextId; + TextIdHashMap textIdPayloads; + uint32_t nextTextId; ContinuousSpace<EventEntry> events; @@ -181,6 +189,7 @@ class TraceLoggerThread : enabled(0), failed(false), graph(), + nextTextId(TraceLogger_Last), iteration_(0), top(nullptr) { } @@ -195,22 +204,22 @@ class TraceLoggerThread bool enable(JSContext* cx); bool disable(); - // Given the previous iteration and lastEntryId, return an array of events + // Given the previous iteration and size, return an array of events // (there could be lost events). At the same time update the iteration and - // lastEntry and gives back how many events there are. - EventEntry* getEventsStartingAt(uint32_t* lastIteration, uint32_t* lastEntryId, size_t* num) { + // size and gives back how many events there are. + EventEntry* getEventsStartingAt(uint32_t* lastIteration, uint32_t* lastSize, size_t* num) { EventEntry* start; if (iteration_ == *lastIteration) { - MOZ_ASSERT(events.lastEntryId() >= *lastEntryId); - *num = events.lastEntryId() - *lastEntryId; - start = events.data() + *lastEntryId + 1; + MOZ_ASSERT(*lastSize <= events.size()); + *num = events.size() - *lastSize; + start = events.data() + *lastSize; } else { - *num = events.lastEntryId() + 1; + *num = events.size(); start = events.data(); } *lastIteration = iteration_; - *lastEntryId = events.lastEntryId(); + *lastSize = events.size(); return start; } @@ -220,16 +229,16 @@ class TraceLoggerThread const char** lineno, size_t* lineno_len, const char** colno, size_t* colno_len); - bool lostEvents(uint32_t lastIteration, uint32_t lastEntryId) { + bool lostEvents(uint32_t lastIteration, uint32_t lastSize) { // If still logging in the same iteration, there are no lost events. if (lastIteration == iteration_) { - MOZ_ASSERT(lastEntryId <= events.lastEntryId()); + MOZ_ASSERT(lastSize <= events.size()); return false; } - // When proceeded to the next iteration and lastEntryId points to - // the maximum capacity there are no logs that are lost. - if (lastIteration + 1 == iteration_ && lastEntryId == events.capacity()) + // If we are in a consecutive iteration we are only sure we didn't lose any events, + // when the lastSize equals the maximum size 'events' can get. + if (lastIteration == iteration_ - 1 && lastSize == events.maxSize()) return false; return true; @@ -268,6 +277,7 @@ class TraceLoggerThread void stopEvent(uint32_t id); private: void stopEvent(); + void log(uint32_t id); public: static unsigned offsetOfEnabled() { diff --git a/js/src/vm/TraceLoggingGraph.cpp b/js/src/vm/TraceLoggingGraph.cpp index d1b7f2e..a4eb273 100644 --- a/js/src/vm/TraceLoggingGraph.cpp +++ b/js/src/vm/TraceLoggingGraph.cpp @@ -276,7 +276,7 @@ TraceLoggerGraph::flush() if (bytesWritten < tree.size()) return false; - treeOffset += tree.lastEntryId(); + treeOffset += tree.size(); tree.clear(); } @@ -359,7 +359,7 @@ TraceLoggerGraph::startEventInternal(uint32_t id, uint64_t timestamp) if (parent.lastChildId() == 0) { MOZ_ASSERT(!entry.hasChildren()); - MOZ_ASSERT(parent.treeId() == tree.lastEntryId() + treeOffset); + MOZ_ASSERT(parent.treeId() == treeOffset + tree.size() - 1); if (!updateHasChildren(parent.treeId())) return false; diff --git a/js/src/vm/TraceLoggingTypes.h b/js/src/vm/TraceLoggingTypes.h index f1c9d0c..10b76d6 100644 --- a/js/src/vm/TraceLoggingTypes.h +++ b/js/src/vm/TraceLoggingTypes.h @@ -21,7 +21,6 @@ _(Internal) \ _(Interpreter) \ _(InlinedScripts) \ - _(Invalidation) \ _(IonCompilation) \ _(IonCompilationPaused) \ _(IonLinking) \ @@ -60,6 +59,7 @@ #define TRACELOGGER_LOG_ITEMS(_) \ _(Bailout) \ + _(Invalidation) \ _(Disable) \ _(Enable) \ _(Stop) @@ -130,6 +130,9 @@ class ContinuousSpace { uint32_t size_; uint32_t capacity_; + // The maximum amount of ram memory a continuous space structure can take (in bytes). + static const uint32_t LIMIT = 200 * 1024 * 1024; + public: ContinuousSpace () : data_(nullptr) @@ -151,6 +154,10 @@ class ContinuousSpace { data_ = nullptr; } + static uint32_t maxSize() { + return LIMIT / sizeof(T); + } + T* data() { return data_; } @@ -187,11 +194,14 @@ class ContinuousSpace { if (hasSpaceForAdd(count)) return true; + // Limit the size of a continuous buffer. + if (size_ + count > maxSize()) + return false; + uint32_t nCapacity = capacity_ * 2; - if (size_ + count > nCapacity) - nCapacity = size_ + count; - T* entries = (T*) js_realloc(data_, nCapacity * sizeof(T)); + nCapacity = (nCapacity < maxSize()) ? nCapacity : maxSize(); + T* entries = (T*) js_realloc(data_, nCapacity * sizeof(T)); if (!entries) return false;