Bug 1413839 - Add telemetry to probe how close we are going to block main thread. r=ngwh, data-r=francois

This commit is contained in:
Junior Hsu 2017-11-21 10:51:11 -05:00
parent 9455f06fb9
commit 5485f27c35
3 changed files with 38 additions and 10 deletions

View File

@ -610,7 +610,6 @@ nsCookieService::nsCookieService()
, mMonitor("CookieThread")
, mInitializedDBStates(false)
, mInitializedDBConn(false)
, mAccumulatedWaitTelemetry(false)
{
}
@ -1449,10 +1448,6 @@ nsCookieService::InitDBConn()
return;
}
if (!mAccumulatedWaitTelemetry) {
mAccumulatedWaitTelemetry = true;
Telemetry::Accumulate(Telemetry::MOZ_SQLITE_COOKIES_BLOCK_MAIN_THREAD_MS, 0);
}
for (uint32_t i = 0; i < mReadArray.Length(); ++i) {
CookieDomainTuple& tuple = mReadArray[i];
RefPtr<nsCookie> cookie = nsCookie::Create(tuple.cookie->name,
@ -1487,6 +1482,7 @@ nsCookieService::InitDBConn()
mInitializedDBConn = true;
COOKIE_LOGSTRING(LogLevel::Debug, ("InitDBConn(): mInitializedDBConn = true"));
mEndInitDBConn = mozilla::TimeStamp::Now();
nsCOMPtr<nsIObserverService> os = mozilla::services::GetObserverService();
if (os && !mReadArray.IsEmpty()) {
@ -2760,6 +2756,8 @@ nsCookieService::EnsureReadComplete(bool aInitDBConn)
{
MOZ_ASSERT(NS_IsMainThread());
bool isAccumulated = false;
if (!mInitializedDBStates) {
TimeStamp startBlockTime = TimeStamp::Now();
MonitorAutoLock lock(mMonitor);
@ -2767,12 +2765,32 @@ nsCookieService::EnsureReadComplete(bool aInitDBConn)
while (!mInitializedDBStates) {
mMonitor.Wait();
}
Telemetry::AccumulateTimeDelta(Telemetry::MOZ_SQLITE_COOKIES_BLOCK_MAIN_THREAD_MS,
Telemetry::AccumulateTimeDelta(Telemetry::MOZ_SQLITE_COOKIES_BLOCK_MAIN_THREAD_MS_V2,
startBlockTime);
mAccumulatedWaitTelemetry = true;
Telemetry::Accumulate(Telemetry::MOZ_SQLITE_COOKIES_TIME_TO_BLOCK_MAIN_THREAD_MS, 0);
isAccumulated = true;
} else if (!mEndInitDBConn.IsNull()) {
// We didn't block main thread, and here comes the first cookie request.
// Collect how close we're going to block main thread.
Telemetry::Accumulate(Telemetry::MOZ_SQLITE_COOKIES_TIME_TO_BLOCK_MAIN_THREAD_MS,
(TimeStamp::Now() - mEndInitDBConn).ToMilliseconds());
// Nullify the timestamp so wo don't accumulate this telemetry probe again.
mEndInitDBConn = TimeStamp();
isAccumulated = true;
} else if (!mInitializedDBConn && aInitDBConn) {
// A request comes while we finished cookie thread task and InitDBConn is
// on the way from cookie thread to main thread. We're very close to block
// main thread.
Telemetry::Accumulate(Telemetry::MOZ_SQLITE_COOKIES_TIME_TO_BLOCK_MAIN_THREAD_MS, 0);
isAccumulated = true;
}
if (!mInitializedDBConn && aInitDBConn && mDefaultDBState) {
InitDBConn();
if (isAccumulated) {
// Nullify the timestamp so wo don't accumulate this telemetry probe again.
mEndInitDBConn = TimeStamp();
}
}
}

View File

@ -365,7 +365,7 @@ class nsCookieService final : public nsICookieService
mozilla::Monitor mMonitor;
mozilla::Atomic<bool> mInitializedDBStates;
mozilla::Atomic<bool> mInitializedDBConn;
bool mAccumulatedWaitTelemetry;
mozilla::TimeStamp mEndInitDBConn;
nsTArray<CookieDomainTuple> mReadArray;
// friends!

View File

@ -4427,7 +4427,7 @@
"alert_emails": ["necko@mozilla.com", "junior@mozilla.com"],
"description": "Old schema version of the cookie database. 0 for having legacy cookies.txt."
},
"MOZ_SQLITE_COOKIES_BLOCK_MAIN_THREAD_MS": {
"MOZ_SQLITE_COOKIES_BLOCK_MAIN_THREAD_MS_V2": {
"record_in_processes": ["main"],
"expires_in_version": "never",
"kind": "exponential",
@ -4435,7 +4435,17 @@
"bug_numbers": [870460],
"high": 3000,
"n_buckets": 10,
"description": "Time spent on blocking main thread by startup cookie database read (ms)"
"description": "Time spent on blocking main thread by startup cookie database read (ms), only for blocking case"
},
"MOZ_SQLITE_COOKIES_TIME_TO_BLOCK_MAIN_THREAD_MS": {
"record_in_processes": ["main"],
"expires_in_version": "never",
"kind": "exponential",
"alert_emails": ["necko@mozilla.com", "junior@mozilla.com"],
"bug_numbers": [1413839],
"high": 10000,
"n_buckets": 30,
"description": "How long (ms) after we finished reading the cookie db until the first cookie request came in (0 implies we blocked the main thread)"
},
"MOZ_SQLITE_COOKIES_READ_MAIN_THREAD_MS": {
"record_in_processes": ["main", "content"],