Bug 1322184 - Measure time spent in content JS that causes delay in paint. r?ehsan
MozReview-Commit-ID: HxXBqQb4yp6
--- a/dom/base/TabGroup.cpp
+++ b/dom/base/TabGroup.cpp
@@ -11,16 +11,18 @@
#include "mozilla/dom/DocGroup.h"
#include "mozilla/ClearOnShutdown.h"
#include "mozilla/StaticPtr.h"
#include "mozilla/Telemetry.h"
#include "mozilla/ThrottledEventQueue.h"
#include "nsIDocShell.h"
#include "nsIEffectiveTLDService.h"
#include "nsIURI.h"
+#include "nsRefreshDriver.h"
+#include "nsThreadUtils.h"
namespace mozilla {
namespace dom {
static StaticRefPtr<TabGroup> sChromeTabGroup;
TabGroup::TabGroup(bool aIsChrome)
: mLastWindowLeft(false)
@@ -230,27 +232,114 @@ TabGroup::GetTopLevelWindows()
}
NS_IMPL_ISUPPORTS(TabGroup, nsISupports)
TabGroup::HashEntry::HashEntry(const nsACString* aKey)
: nsCStringHashKey(aKey), mDocGroup(nullptr)
{}
+class TelemetryWrapper : public Runnable
+{
+public:
+ TelemetryWrapper(TabGroup* aTabGroup, nsIRunnable* aRunnable,
+ const char* aName)
+ : mTabGroup(aTabGroup)
+ , mRunnable(aRunnable)
+ , mKey(aName ? aName : "unlabelled")
+ {
+ }
+
+ NS_IMETHOD
+ Run()
+ {
+ bool allBackground = true;
+ for (nsPIDOMWindowOuter* outerWindow : mTabGroup->GetTopLevelWindows()) {
+ if (!outerWindow->IsBackground()) {
+ allBackground = false;
+ }
+ }
+
+ NS_NAMED_LITERAL_CSTRING(totalKey, "TOTAL");
+ Telemetry::AutoCancellableTimer<
+ Telemetry::CONTENT_JS_FOREGROUND_TICK_DELAY_MS>
+ foregroundTimer(mKey);
+ Telemetry::AutoCancellableTimer<
+ Telemetry::CONTENT_JS_FOREGROUND_TICK_DELAY_MS>
+ foregroundTimerTotal(totalKey);
+
+ Telemetry::AutoCancellableTimer<
+ Telemetry::CONTENT_JS_BACKGROUND_TICK_DELAY_MS>
+ backgroundTimer(mKey);
+ Telemetry::AutoCancellableTimer<
+ Telemetry::CONTENT_JS_BACKGROUND_TICK_DELAY_MS>
+ backgroundTimerTotal(totalKey);
+
+ if (allBackground) {
+ foregroundTimer.Cancel();
+ foregroundTimerTotal.Cancel();
+ } else {
+ backgroundTimer.Cancel();
+ backgroundTimerTotal.Cancel();
+ }
+
+ nsresult result = mRunnable->Run();
+
+ if (!nsRefreshDriver::IsCurrentDriverDelayed()) {
+ foregroundTimer.Cancel();
+ foregroundTimerTotal.Cancel();
+ backgroundTimer.Cancel();
+ backgroundTimerTotal.Cancel();
+ }
+
+ return result;
+ }
+
+private:
+ virtual ~TelemetryWrapper() {}
+
+ RefPtr<TabGroup> mTabGroup;
+ nsCOMPtr<nsIRunnable> mRunnable;
+ nsCString mKey;
+};
+
+already_AddRefed<nsIRunnable>
+TabGroup::MaybeWrapRunnable(already_AddRefed<nsIRunnable>&& aRunnable,
+ const char* aName)
+{
+ nsCOMPtr<nsIRunnable> runnable(aRunnable);
+
+ if (aName) {
+ if (nsCOMPtr<nsINamed> named = do_QueryInterface(runnable)) {
+ named->SetName(aName);
+ }
+ }
+
+#ifdef EARLY_BETA_OR_EARLIER
+ if (Telemetry::CanRecordBase()) {
+ runnable = new TelemetryWrapper(this, runnable, aName);
+
+ if (aName) {
+ if (nsCOMPtr<nsINamed> named = do_QueryInterface(runnable)) {
+ named->SetName(aName);
+ }
+ }
+ }
+#endif
+
+ return runnable.forget();
+}
+
nsresult
TabGroup::Dispatch(const char* aName,
TaskCategory aCategory,
already_AddRefed<nsIRunnable>&& aRunnable)
{
- nsCOMPtr<nsIRunnable> runnable(aRunnable);
- if (aName) {
- if (nsCOMPtr<nsINamed> named = do_QueryInterface(runnable)) {
- named->SetName(aName);
- }
- }
+ nsCOMPtr<nsIRunnable> runnable = MaybeWrapRunnable(Move(aRunnable), aName);
+
if (NS_IsMainThread()) {
return NS_DispatchToCurrentThread(runnable.forget());
} else {
return NS_DispatchToMainThread(runnable.forget());
}
}
nsIEventTarget*
--- a/dom/base/TabGroup.h
+++ b/dom/base/TabGroup.h
@@ -119,16 +119,20 @@ public:
// can always be used off the main thread.
virtual nsIEventTarget* EventTargetFor(TaskCategory aCategory) const override;
TabGroup* AsTabGroup() override { return this; }
private:
void EnsureThrottledEventQueues();
+ already_AddRefed<nsIRunnable>
+ MaybeWrapRunnable(already_AddRefed<nsIRunnable>&& aRunnable,
+ const char* aName);
+
~TabGroup();
DocGroupMap mDocGroups;
Atomic<bool> mLastWindowLeft;
nsTArray<nsPIDOMWindowOuter*> mWindows;
Atomic<bool> mThrottledQueuesInitialized;
nsCOMPtr<nsIEventTarget> mEventTargets[size_t(TaskCategory::Count)];
};
--- a/layout/base/nsRefreshDriver.cpp
+++ b/layout/base/nsRefreshDriver.cpp
@@ -247,16 +247,33 @@ public:
TimeStamp::Now()) {
return Nothing();
}
return Some(idleEnd - TimeDuration::FromMilliseconds(
nsLayoutUtils::IdlePeriodDeadlineLimit()));
}
+ bool AnyDriverWaitingForTransaction()
+ {
+ for (auto driver : mContentRefreshDrivers) {
+ if (driver->mWaitingForTransaction) {
+ return true;
+ }
+ }
+
+ for (auto driver : mRootRefreshDrivers) {
+ if (driver->mWaitingForTransaction) {
+ return true;
+ }
+ }
+
+ return false;
+ }
+
protected:
virtual void StartTimer() = 0;
virtual void StopTimer() = 0;
virtual void ScheduleNextTick(TimeStamp aNowTime) = 0;
bool IsRootRefreshDriver(nsRefreshDriver* aDriver)
{
nsPresContext* pc = aDriver->GetPresContext();
@@ -2323,16 +2340,33 @@ nsRefreshDriver::GetIdleDeadlineHint()
// sRegularRateTimer, since we consider refresh drivers attached to
// sThrottledRateTimer to be inactive. This implies that tasks
// resulting from a tick on the sRegularRateTimer counts as being
// busy but tasks resulting from a tick on sThrottledRateTimer
// counts as being idle.
return sRegularRateTimer->GetIdleDeadlineHint();
}
+/* static */ bool
+nsRefreshDriver::IsCurrentDriverDelayed()
+{
+ MOZ_ASSERT(NS_IsMainThread());
+
+ if (!sRegularRateTimer) {
+ return false;
+ }
+
+ if (sRegularRateTimer->AnyDriverWaitingForTransaction()) {
+ return TimeStamp::Now() - sRegularRateTimer->MostRecentRefresh() >
+ sRegularRateTimer->GetTimerRate();
+ }
+
+ return false;
+}
+
void
nsRefreshDriver::Disconnect()
{
MOZ_ASSERT(NS_IsMainThread());
StopTimer();
if (mPresContext) {
--- a/layout/base/nsRefreshDriver.h
+++ b/layout/base/nsRefreshDriver.h
@@ -360,16 +360,18 @@ public:
* drivers attached to the current refresh driver misses a paint.
*
* Returning Some(TimeStamp(t)) indicates to nsThread that we will
* be idle until. This is usually the case when we're animating
* without skipping paints.
*/
static mozilla::Maybe<mozilla::TimeStamp> GetIdleDeadlineHint();
+ static bool IsCurrentDriverDelayed();
+
bool SkippedPaints() const
{
return mSkippedPaints;
}
private:
typedef nsTObserverArray<nsARefreshObserver*> ObserverArray;
typedef nsTHashtable<nsISupportsHashKey> RequestTable;
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -1,9 +1,8 @@
-
{
"A11Y_INSTANTIATED_FLAG": {
"expires_in_version": "never",
"kind": "flag",
"description": "has accessibility support been instantiated"
},
"A11Y_CONSUMERS": {
"expires_in_version": "default",
@@ -181,16 +180,36 @@
},
"COMPOSITE_FRAME_ROUNDTRIP_TIME" : {
"expires_in_version": "never",
"description": "Time from vsync to finishing a composite in milliseconds.",
"kind": "exponential",
"high": 1000,
"n_buckets": 50
},
+ "CONTENT_JS_FOREGROUND_TICK_DELAY_MS": {
+ "alert_emails": ["farre@mozilla.com"],
+ "expires_in_version": "60",
+ "keyed": true,
+ "kind": "exponential",
+ "high": 60000,
+ "n_buckets": 50,
+ "bug_numbers": [1305153, 1296486],
+ "description": "Time spent executing foreground content JS causing refresh driver tick delay"
+ },
+ "CONTENT_JS_BACKGROUND_TICK_DELAY_MS": {
+ "alert_emails": ["farre@mozilla.com"],
+ "expires_in_version": "60",
+ "keyed": true,
+ "kind": "exponential",
+ "high": 60000,
+ "n_buckets": 50,
+ "bug_numbers": [1305153, 1296486],
+ "description": "Time spent executing background content JS causing refresh driver tick delay"
+ },
"CONTENT_PROCESS_LAUNCH_TIME_MS" : {
"alert_emails": ["bsmedberg@mozilla.com", "mconley@mozilla.com"],
"expires_in_version": "57",
"bug_numbers": [1304790],
"kind": "exponential",
"high": 64000,
"n_buckets": 100,
"releaseChannelCollection": "opt-out",
--- a/toolkit/components/telemetry/Telemetry.h
+++ b/toolkit/components/telemetry/Telemetry.h
@@ -242,16 +242,57 @@ public:
counter += increment;
}
private:
uint32_t counter;
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
};
+template<ID id, TimerResolution res = Millisecond>
+class MOZ_RAII AutoCancellableTimer {
+public:
+ explicit AutoCancellableTimer(TimeStamp aStart = TimeStamp::Now() MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
+ : isCancelled(false)
+ , start(aStart)
+ {
+ MOZ_GUARD_OBJECT_NOTIFIER_INIT;
+ }
+
+ explicit AutoCancellableTimer(const nsCString& aKey, TimeStamp aStart = TimeStamp::Now() MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
+ : isCancelled(false)
+ , start(aStart)
+ , key(aKey)
+ {
+ MOZ_GUARD_OBJECT_NOTIFIER_INIT;
+ }
+
+ ~AutoCancellableTimer() {
+ if (isCancelled) {
+ return;
+ }
+
+ if (key.IsEmpty()) {
+ AccumulateDelta_impl<res>::compute(id, start);
+ } else {
+ AccumulateDelta_impl<res>::compute(id, key, start);
+ }
+ }
+
+ void Cancel() {
+ isCancelled = true;
+ }
+
+private:
+ bool isCancelled;
+ const TimeStamp start;
+ const nsCString key;
+ MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
+};
+
/**
* Indicates whether Telemetry base data recording is turned on. Added for future uses.
*/
bool CanRecordBase();
/**
* Indicates whether Telemetry extended data recording is turned on. This is intended
* to guard calls to Accumulate when the statistic being recorded is expensive to compute.