Bug 1069661 - add "detail" to timeline markers. r=smaug

This commit is contained in:
Tom Tromey 2014-11-18 14:39:00 +01:00
parent a2acd9f713
commit 986dfd2fd6
9 changed files with 184 additions and 88 deletions

View File

@ -287,10 +287,10 @@ Waterfall.prototype = {
name.className = "plain waterfall-marker-name";
let label;
if (marker.detail && marker.detail.causeName) {
if (marker.causeName) {
label = this._l10n.getFormatStr("timeline.markerDetailFormat",
blueprint.label,
marker.detail.causeName);
marker.causeName);
} else {
label = blueprint.label;
}

View File

@ -2886,12 +2886,11 @@ nsDocShell::PopProfileTimelineMarkers(JSContext* aCx,
// If we see an unpaired START, we keep it around for the next call
// to PopProfileTimelineMarkers. We store the kept START objects in
// this array.
nsTArray<InternalProfileTimelineMarker*> keptMarkers;
nsTArray<TimelineMarker*> keptMarkers;
for (uint32_t i = 0; i < mProfileTimelineMarkers.Length(); ++i) {
ProfilerMarkerTracing* startPayload = static_cast<ProfilerMarkerTracing*>(
mProfileTimelineMarkers[i]->mPayload);
const char* startMarkerName = mProfileTimelineMarkers[i]->mName.get();
TimelineMarker* startPayload = mProfileTimelineMarkers[i];
const char* startMarkerName = startPayload->GetName();
bool hasSeenPaintedLayer = false;
@ -2907,16 +2906,15 @@ nsDocShell::PopProfileTimelineMarkers(JSContext* aCx,
// enough for the amount of markers to always be small enough that the
// nested for loop isn't going to be a performance problem.
for (uint32_t j = i + 1; j < mProfileTimelineMarkers.Length(); ++j) {
ProfilerMarkerTracing* endPayload = static_cast<ProfilerMarkerTracing*>(
mProfileTimelineMarkers[j]->mPayload);
const char* endMarkerName = mProfileTimelineMarkers[j]->mName.get();
TimelineMarker* endPayload = mProfileTimelineMarkers[j];
const char* endMarkerName = endPayload->GetName();
// Look for Layer markers to stream out paint markers.
if (strcmp(endMarkerName, "Layer") == 0) {
hasSeenPaintedLayer = true;
}
if (strcmp(startMarkerName, endMarkerName) != 0) {
if (!startPayload->Equals(endPayload)) {
continue;
}
bool isPaint = strcmp(startMarkerName, "Paint") == 0;
@ -2931,9 +2929,11 @@ nsDocShell::PopProfileTimelineMarkers(JSContext* aCx,
// But ignore paint start/end if no layer has been painted.
if (!isPaint || (isPaint && hasSeenPaintedLayer)) {
mozilla::dom::ProfileTimelineMarker marker;
marker.mName = NS_ConvertUTF8toUTF16(startMarkerName);
marker.mStart = mProfileTimelineMarkers[i]->mTime;
marker.mEnd = mProfileTimelineMarkers[j]->mTime;
marker.mName = NS_ConvertUTF8toUTF16(startPayload->GetName());
marker.mStart = startPayload->GetTime();
marker.mEnd = endPayload->GetTime();
startPayload->AddDetails(marker);
profileTimelineMarkers.AppendElement(marker);
}
@ -2982,30 +2982,18 @@ nsDocShell::AddProfileTimelineMarker(const char* aName,
{
#ifdef MOZ_ENABLE_PROFILER_SPS
if (mProfileTimelineRecording) {
DOMHighResTimeStamp delta;
Now(&delta);
ProfilerMarkerTracing* payload = new ProfilerMarkerTracing("Timeline",
aMetaData);
mProfileTimelineMarkers.AppendElement(
new InternalProfileTimelineMarker(aName, payload, delta));
TimelineMarker* marker = new TimelineMarker(this, aName, aMetaData);
mProfileTimelineMarkers.AppendElement(marker);
}
#endif
}
void
nsDocShell::AddProfileTimelineMarker(const char* aName,
ProfilerBacktrace* aCause,
TracingMetadata aMetaData)
nsDocShell::AddProfileTimelineMarker(UniquePtr<TimelineMarker>& aMarker)
{
#ifdef MOZ_ENABLE_PROFILER_SPS
if (mProfileTimelineRecording) {
DOMHighResTimeStamp delta;
Now(&delta);
ProfilerMarkerTracing* payload = new ProfilerMarkerTracing("Timeline",
aMetaData,
aCause);
mProfileTimelineMarkers.AppendElement(
new InternalProfileTimelineMarker(aName, payload, delta));
mProfileTimelineMarkers.AppendElement(aMarker.release());
}
#endif
}

View File

@ -18,12 +18,11 @@
#include "nsIContentViewerContainer.h"
#include "nsIDOMStorageManager.h"
#include "nsDocLoader.h"
#include "mozilla/UniquePtr.h"
#include "mozilla/WeakPtr.h"
#include "mozilla/TimeStamp.h"
#include "GeckoProfiler.h"
#ifdef MOZ_ENABLE_PROFILER_SPS
#include "ProfilerMarkers.h"
#endif
#include "mozilla/dom/ProfileTimelineMarkerBinding.h"
// Helper Classes
#include "nsCOMPtr.h"
@ -259,14 +258,86 @@ public:
// is no longer applied
void NotifyAsyncPanZoomStopped(const mozilla::CSSIntPoint aScrollPos);
// Objects of this type can be added to the timeline. The class
// can also be subclassed to let a given marker creator provide
// custom details.
class TimelineMarker
{
public:
TimelineMarker(nsDocShell* aDocShell, const char* aName,
TracingMetadata aMetaData)
: mName(aName)
, mMetaData(aMetaData)
{
MOZ_COUNT_CTOR(TimelineMarker);
MOZ_ASSERT(aName);
aDocShell->Now(&mTime);
}
TimelineMarker(nsDocShell* aDocShell, const char* aName,
TracingMetadata aMetaData,
const nsAString& aCause)
: mName(aName)
, mMetaData(aMetaData)
, mCause(aCause)
{
MOZ_COUNT_CTOR(TimelineMarker);
MOZ_ASSERT(aName);
aDocShell->Now(&mTime);
}
virtual ~TimelineMarker()
{
MOZ_COUNT_DTOR(TimelineMarker);
}
// Check whether two markers should be considered the same,
// for the purpose of pairing start and end markers. Normally
// this definition suffices.
virtual bool Equals(const TimelineMarker* other)
{
return strcmp(mName, other->mName) == 0;
}
// Add details specific to this marker type to aMarker. The
// standard elements have already been set.
virtual void AddDetails(mozilla::dom::ProfileTimelineMarker& aMarker)
{
}
const char* GetName() const
{
return mName;
}
TracingMetadata GetMetaData() const
{
return mMetaData;
}
DOMHighResTimeStamp GetTime() const
{
return mTime;
}
const nsString& GetCause() const
{
return mCause;
}
private:
const char* mName;
TracingMetadata mMetaData;
DOMHighResTimeStamp mTime;
nsString mCause;
};
// Add new profile timeline markers to this docShell. This will only add
// markers if the docShell is currently recording profile timeline markers.
// See nsIDocShell::recordProfileTimelineMarkers
void AddProfileTimelineMarker(const char* aName,
TracingMetadata aMetaData);
void AddProfileTimelineMarker(const char* aName,
ProfilerBacktrace* aCause,
TracingMetadata aMetaData);
void AddProfileTimelineMarker(mozilla::UniquePtr<TimelineMarker> &aMarker);
// Global counter for how many docShells are currently recording profile
// timeline markers
@ -960,28 +1031,7 @@ private:
// True if recording profiles.
bool mProfileTimelineRecording;
#ifdef MOZ_ENABLE_PROFILER_SPS
struct InternalProfileTimelineMarker
{
InternalProfileTimelineMarker(const char* aName,
ProfilerMarkerTracing* aPayload,
DOMHighResTimeStamp aTime)
: mName(aName)
, mPayload(aPayload)
, mTime(aTime)
{}
~InternalProfileTimelineMarker()
{
delete mPayload;
}
nsCString mName;
ProfilerMarkerTracing* mPayload;
DOMHighResTimeStamp mTime;
};
nsTArray<InternalProfileTimelineMarker*> mProfileTimelineMarkers;
#endif
nsTArray<TimelineMarker*> mProfileTimelineMarkers;
// Get rid of all the timeline markers accumulated so far
void ClearProfileTimelineMarkers();

View File

@ -54,7 +54,8 @@ let TESTS = [{
content.console.timeEnd("FOOBAR");
let markers = docShell.popProfileTimelineMarkers();
is(markers.length, 1, "Got one marker");
is(markers[0].name, "ConsoleTime:FOOBAR", "Got ConsoleTime:FOOBAR marker");
is(markers[0].name, "ConsoleTime", "Got ConsoleTime marker");
is(markers[0].causeName, "FOOBAR", "Got ConsoleTime FOOBAR detail");
content.console.time("FOO");
content.setTimeout(() => {
content.console.time("BAR");
@ -66,8 +67,10 @@ let TESTS = [{
},
check: function(markers) {
is(markers.length, 2, "Got 2 markers");
is(markers[0].name, "ConsoleTime:FOO", "Got ConsoleTime:FOO marker");
is(markers[1].name, "ConsoleTime:BAR", "Got ConsoleTime:BARmarker");
is(markers[0].name, "ConsoleTime", "Got first ConsoleTime marker");
is(markers[0].causeName, "FOO", "Got ConsoleTime FOO detail");
is(markers[1].name, "ConsoleTime", "Got second ConsoleTime marker");
is(markers[1].causeName, "BAR", "Got ConsoleTime BAR detail");
}
}];

View File

@ -16,6 +16,8 @@ let TESTS = [{
},
check: function(markers) {
is(markers.length, 1, "Got 1 marker");
is(markers[0].type, "dog", "Got dog event name");
is(markers[0].eventPhase, 2, "Got phase 2");
}
}, {
desc: "Event dispatch with a second handler",
@ -28,6 +30,18 @@ let TESTS = [{
check: function(markers) {
is(markers.length, 2, "Got 2 markers");
}
}, {
desc: "Event targeted at child",
setup: function() {
let child = content.document.body.firstElementChild;
child.addEventListener("dog", function(e) { });
child.dispatchEvent(new Event("dog"));
},
check: function(markers) {
is(markers.length, 2, "Got 2 markers");
is(markers[0].eventPhase, 1, "Got phase 1 marker");
is(markers[1].eventPhase, 2, "Got phase 2 marker");
}
}, {
desc: "Event dispatch on a new document",
setup: function() {
@ -59,7 +73,7 @@ let TESTS = [{
let test = Task.async(function*() {
waitForExplicitFinish();
yield openUrl("data:text/html;charset=utf-8,Test page");
yield openUrl("data:text/html;charset=utf-8,<p>Test page</p>");
let docShell = content.QueryInterface(Ci.nsIInterfaceRequestor)
.getInterface(Ci.nsIWebNavigation)

View File

@ -805,6 +805,31 @@ ReifyStack(nsIStackFrame* aStack, nsTArray<ConsoleStackEntry>& aRefiedStack)
return NS_OK;
}
class ConsoleTimelineMarker : public nsDocShell::TimelineMarker
{
public:
ConsoleTimelineMarker(nsDocShell* aDocShell,
TracingMetadata aMetaData,
const nsAString& aCause)
: nsDocShell::TimelineMarker(aDocShell, "ConsoleTime", aMetaData, aCause)
{
}
virtual bool Equals(const nsDocShell::TimelineMarker* aOther)
{
if (!nsDocShell::TimelineMarker::Equals(aOther)) {
return false;
}
// Console markers must have matching causes as well.
return GetCause() == aOther->GetCause();
}
virtual void AddDetails(mozilla::dom::ProfileTimelineMarker& aMarker)
{
aMarker.mCauseName.Construct(GetCause());
}
};
// Queue a call to a console method. See the CALL_DELAY constant.
void
Console::Method(JSContext* aCx, MethodName aMethodName,
@ -925,7 +950,6 @@ Console::Method(JSContext* aCx, MethodName aMethodName,
callData->mMonotonicTimer = performance->Now();
// 'time' and 'timeEnd' are displayed in the devtools timeline if active.
// Marked as "ConsoleTime:ARG1".
bool isTimelineRecording = false;
nsDocShell* docShell = static_cast<nsDocShell*>(mWindow->GetDocShell());
if (docShell) {
@ -938,10 +962,11 @@ Console::Method(JSContext* aCx, MethodName aMethodName,
if (jsString) {
nsAutoJSString key;
if (key.init(aCx, jsString)) {
nsCString str("ConsoleTime:");
AppendUTF16toUTF8(key, str);
docShell->AddProfileTimelineMarker(str.get(),
aMethodName == MethodTime ? TRACING_INTERVAL_START : TRACING_INTERVAL_END);
mozilla::UniquePtr<nsDocShell::TimelineMarker> marker =
MakeUnique<ConsoleTimelineMarker>(docShell,
aMethodName == MethodTime ? TRACING_INTERVAL_START : TRACING_INTERVAL_END,
key);
docShell->AddProfileTimelineMarker(marker);
}
}
}

View File

@ -1012,6 +1012,26 @@ EventListenerManager::GetDocShellForTarget()
return docShell;
}
class EventTimelineMarker : public nsDocShell::TimelineMarker
{
public:
EventTimelineMarker(nsDocShell* aDocShell, TracingMetadata aMetaData,
uint16_t aPhase, const nsAString& aCause)
: nsDocShell::TimelineMarker(aDocShell, "DOMEvent", aMetaData, aCause)
, mPhase(aPhase)
{
}
virtual void AddDetails(mozilla::dom::ProfileTimelineMarker& aMarker)
{
aMarker.mType.Construct(GetCause());
aMarker.mEventPhase.Construct(mPhase);
}
private:
uint16_t mPhase;
};
/**
* Causes a check for event listeners and processing by them if they exist.
* @param an event listener
@ -1066,13 +1086,24 @@ EventListenerManager::HandleEventInternal(nsPresContext* aPresContext,
// Maybe add a marker to the docshell's timeline, but only
// bother with all the logic if some docshell is recording.
nsCOMPtr<nsIDocShell> docShell;
bool isTimelineRecording = false;
if (mIsMainThreadELM &&
nsDocShell::gProfileTimelineRecordingsCount > 0 &&
listener->mListenerType != Listener::eNativeListener) {
docShell = GetDocShellForTarget();
if (docShell) {
docShell->GetRecordProfileTimelineMarkers(&isTimelineRecording);
}
if (isTimelineRecording) {
nsDocShell* ds = static_cast<nsDocShell*>(docShell.get());
ds->AddProfileTimelineMarker("DOMEvent", TRACING_INTERVAL_START);
nsAutoString typeStr;
(*aDOMEvent)->GetType(typeStr);
uint16_t phase;
(*aDOMEvent)->GetEventPhase(&phase);
mozilla::UniquePtr<nsDocShell::TimelineMarker> marker =
MakeUnique<EventTimelineMarker>(ds, TRACING_INTERVAL_START,
phase, typeStr);
ds->AddProfileTimelineMarker(marker);
}
}
@ -1081,7 +1112,7 @@ EventListenerManager::HandleEventInternal(nsPresContext* aPresContext,
aEvent->mFlags.mExceptionHasBeenRisen = true;
}
if (docShell) {
if (isTimelineRecording) {
nsDocShell* ds = static_cast<nsDocShell*>(docShell.get());
ds->AddProfileTimelineMarker("DOMEvent", TRACING_INTERVAL_END);
}

View File

@ -8,4 +8,9 @@ dictionary ProfileTimelineMarker {
DOMString name = "";
DOMHighResTimeStamp start = 0;
DOMHighResTimeStamp end = 0;
/* For ConsoleTime markers. */
DOMString causeName;
/* For DOMEvent markers. */
DOMString type;
unsigned short eventPhase;
};

View File

@ -158,7 +158,6 @@ let TimelineActor = exports.TimelineActor = protocol.ActorClass({
}
if (markers.length > 0) {
this._postProcessMarkers(markers);
events.emit(this, "markers", markers, endTime);
}
if (this._memoryActor) {
@ -173,25 +172,6 @@ let TimelineActor = exports.TimelineActor = protocol.ActorClass({
}, DEFAULT_TIMELINE_DATA_PULL_TIMEOUT);
},
/**
* Some markers need post processing.
* We will eventually do that platform side: bug 1069661
*/
_postProcessMarkers: function(m) {
m.forEach(m => {
// A marker named "ConsoleTime:foobar" needs
// to be renamed "ConsoleTime".
let split = m.name.match(/ConsoleTime:(.*)/);
if (split && split.length > 0) {
if (!m.detail) {
m.detail = {}
}
m.detail.causeName = split[1];
m.name = "ConsoleTime";
}
});
},
/**
* Are we recording profile markers currently?
*/