Magic-Mirror/gecko-dev
1
0
Fork 0
mirror of https://github.com/mozilla/gecko-dev.git synced 2024-10-13 21:35:39 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

Bug 1070755: Telemetry to track total time that the main thread is blocked during plugin initialization; r=vladan (Relanding because I meant to back out a different commit for bustage, not this) CLOSED TREE

Browse Source
This commit is contained in:
Aaron Klotz 2014-12-11 14:00:47 -07:00
parent 821c1dde56
commit 165993e17f
5 changed files with 131 additions and 23 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

33
dom/plugins/ipc/PluginInstanceParent.cpp
View File

@ -7,6 +7,7 @@
#include "mozilla/DebugOnly.h"
#include <stdint.h> // for intptr_t
#include "mozilla/Telemetry.h"
#include "PluginInstanceParent.h"
#include "BrowserStreamParent.h"
#include "PluginBackgroundDestroyer.h"
@ -145,8 +146,13 @@ NPError
PluginInstanceParent::Destroy()
{
NPError retval;
if (!CallNPP_Destroy(&retval))
retval = NPERR_GENERIC_ERROR;
{ // Scope for timer
Telemetry::AutoTimer<Telemetry::BLOCKED_ON_PLUGIN_INSTANCE_DESTROY_MS>
timer(Module()->GetHistogramKey());
if (!CallNPP_Destroy(&retval)) {
retval = NPERR_GENERIC_ERROR;
}
}
#if defined(OS_WIN)
SharedSurfaceRelease();
@ -1304,15 +1310,20 @@ PluginInstanceParent::NPP_NewStream(NPMIMEType type, NPStream* stream,
BrowserStreamParent* bs = new BrowserStreamParent(this, stream);
NPError err;
if (!CallPBrowserStreamConstructor(bs,
NullableString(stream->url),
stream->end,
stream->lastmodified,
static_cast<PStreamNotifyParent*>(stream->notifyData),
NullableString(stream->headers),
NullableString(type), seekable,
&err, stype))
return NPERR_GENERIC_ERROR;
{ // Scope for timer
Telemetry::AutoTimer<Telemetry::BLOCKED_ON_PLUGIN_STREAM_INIT_MS>
timer(Module()->GetHistogramKey());
if (!CallPBrowserStreamConstructor(bs,
NullableString(stream->url),
stream->end,
stream->lastmodified,
static_cast<PStreamNotifyParent*>(stream->notifyData),
NullableString(stream->headers),
NullableString(type), seekable,
&err, stype)) {
return NPERR_GENERIC_ERROR;
}
}
if (NPERR_NO_ERROR != err)
unused << PBrowserStreamParent::Send__delete__(bs);

58
dom/plugins/ipc/PluginModuleParent.cpp
View File

@ -21,6 +21,7 @@
#include "mozilla/plugins/PluginInstanceParent.h"
#include "mozilla/Preferences.h"
#include "mozilla/Services.h"
#include "mozilla/Telemetry.h"
#include "mozilla/unused.h"
#include "nsAutoPtr.h"
#include "nsCRT.h"
@ -160,12 +161,15 @@ PluginModuleChromeParent::LoadModule(const char* aFilePath, uint32_t aPluginId)
// Block on the child process being launched and initialized.
nsAutoPtr<PluginModuleChromeParent> parent(new PluginModuleChromeParent(aFilePath, aPluginId));
TimeStamp launchStart = TimeStamp::Now();
bool launched = parent->mSubprocess->Launch(prefSecs * 1000);
if (!launched) {
// We never reached open
parent->mShutdown = true;
return nullptr;
}
TimeStamp launchEnd = TimeStamp::Now();
parent->mTimeBlocked = (launchEnd - launchStart);
parent->Open(parent->mSubprocess->GetChannel(),
parent->mSubprocess->GetChildProcessHandle());
@ -1378,6 +1382,7 @@ PluginModuleParent::NP_Initialize(NPNetscapeFuncs* bFuncs, NPPluginFuncs* pFuncs
if (IsChrome()) {
PluginSettings settings;
GetSettings(&settings);
TimeStamp callNpInitStart = TimeStamp::Now();
if (!CallNP_Initialize(settings, error)) {
Close();
return NS_ERROR_FAILURE;
@ -1386,6 +1391,16 @@ PluginModuleParent::NP_Initialize(NPNetscapeFuncs* bFuncs, NPPluginFuncs* pFuncs
Close();
return NS_OK;
}
TimeStamp callNpInitEnd = TimeStamp::Now();
mTimeBlocked += (callNpInitEnd - callNpInitStart);
/** mTimeBlocked measures the time that the main thread has been blocked
* on plugin module initialization. As implemented, this is the sum of
* plugin-container launch + NP_Initialize
*/
Telemetry::Accumulate(Telemetry::BLOCKED_ON_PLUGIN_MODULE_INIT_MS,
GetHistogramKey(),
static_cast<uint32_t>(mTimeBlocked.ToMilliseconds()));
mTimeBlocked = TimeDuration();
}
SetPluginFuncs(pFuncs);
@ -1418,6 +1433,7 @@ PluginModuleChromeParent::NP_Initialize(NPNetscapeFuncs* bFuncs, NPError* error)
PluginSettings settings;
GetSettings(&settings);
TimeStamp callNpInitStart = TimeStamp::Now();
if (!CallNP_Initialize(settings, error)) {
Close();
return NS_ERROR_FAILURE;
@ -1426,6 +1442,8 @@ PluginModuleChromeParent::NP_Initialize(NPNetscapeFuncs* bFuncs, NPError* error)
Close();
return NS_OK;
}
TimeStamp callNpInitEnd = TimeStamp::Now();
mTimeBlocked += (callNpInitEnd - callNpInitStart);
#if defined XP_WIN
// Send the info needed to join the chrome process's audio session to the
@ -1443,6 +1461,17 @@ PluginModuleChromeParent::NP_Initialize(NPNetscapeFuncs* bFuncs, NPError* error)
InitializeInjector();
#endif
/** This Accumulate must be placed below the call to InitializeInjector()
* because mTimeBlocked is modified in that function.
* mTimeBlocked measures the time that the main thread has been blocked
* on plugin module initialization. As implemented, this is the sum of
* plugin-container launch + toolhelp32 snapshot + NP_Initialize
*/
Telemetry::Accumulate(Telemetry::BLOCKED_ON_PLUGIN_MODULE_INIT_MS,
GetHistogramKey(),
static_cast<uint32_t>(mTimeBlocked.ToMilliseconds()));
mTimeBlocked = TimeDuration();
return NS_OK;
}
#endif
@ -1556,17 +1585,21 @@ PluginModuleParent::NPP_New(NPMIMEType pluginType, NPP instance,
instance->pdata = parentInstance;
if (!CallPPluginInstanceConstructor(parentInstance,
nsDependentCString(pluginType), mode,
names, values, error)) {
// |parentInstance| is automatically deleted.
instance->pdata = nullptr;
// if IPC is down, we'll get an immediate "failed" return, but
// without *error being set. So make sure that the error
// condition is signaled to nsNPAPIPluginInstance
if (NPERR_NO_ERROR == *error)
*error = NPERR_GENERIC_ERROR;
return NS_ERROR_FAILURE;
{ // Scope for timer
Telemetry::AutoTimer<Telemetry::BLOCKED_ON_PLUGIN_INSTANCE_INIT_MS>
timer(GetHistogramKey());
if (!CallPPluginInstanceConstructor(parentInstance,
nsDependentCString(pluginType), mode,
names, values, error)) {
// |parentInstance| is automatically deleted.
instance->pdata = nullptr;
// if IPC is down, we'll get an immediate "failed" return, but
// without *error being set. So make sure that the error
// condition is signaled to nsNPAPIPluginInstance
if (NPERR_NO_ERROR == *error)
*error = NPERR_GENERIC_ERROR;
return NS_ERROR_FAILURE;
}
}
if (*error != NPERR_NO_ERROR) {
@ -1913,9 +1946,12 @@ PluginModuleChromeParent::InitializeInjector()
NS_LITERAL_CSTRING(FLASH_PLUGIN_PREFIX)))
return;
TimeStamp th32Start = TimeStamp::Now();
HANDLE snapshot = CreateToolhelp32Snapshot(TH32CS_SNAPPROCESS, 0);
if (INVALID_HANDLE_VALUE == snapshot)
return;
TimeStamp th32End = TimeStamp::Now();
mTimeBlocked += (th32End - th32Start);
DWORD pluginProcessPID = GetProcessId(Process()->GetChildProcessHandle());
mFlashProcess1 = GetFlashChildOfPID(pluginProcessPID, snapshot);

6
dom/plugins/ipc/PluginModuleParent.h
View File

@ -16,6 +16,7 @@
#include "mozilla/plugins/PPluginModuleParent.h"
#include "mozilla/plugins/PluginMessageUtils.h"
#include "mozilla/plugins/PluginTypes.h"
#include "mozilla/TimeStamp.h"
#include "npapi.h"
#include "npfunctions.h"
#include "nsAutoPtr.h"
@ -105,6 +106,10 @@ public:
void ProcessRemoteNativeEventsInInterruptCall();
nsCString GetHistogramKey() const {
return mPluginName + mPluginVersion;
}
protected:
virtual mozilla::ipc::RacyInterruptPolicy
MediateInterruptRace(const Message& parent, const Message& child) MOZ_OVERRIDE
@ -245,6 +250,7 @@ protected:
nsString mBrowserDumpID;
nsString mHangID;
nsRefPtr<nsIObserver> mProfilerObserver;
TimeDuration mTimeBlocked;
nsCString mPluginName;
nsCString mPluginVersion;

36
toolkit/components/telemetry/Histograms.json
View File

@ -6922,6 +6922,42 @@
"kind": "boolean",
"description": "Whether the e10s pref was set but it was blocked from running due to blacklisted conditions"
},
"BLOCKED_ON_PLUGIN_MODULE_INIT_MS": {
"expires_in_version": "40",
"kind": "exponential",
"high": "10000",
"n_buckets": 20,
"extended_statistics_ok": true,
"keyed": true,
"description": "Time (ms) that the main thread has been blocked on LoadModule and NP_Initialize in PluginModuleParent"
},
"BLOCKED_ON_PLUGIN_INSTANCE_INIT_MS": {
"expires_in_version": "40",
"kind": "exponential",
"high": "10000",
"n_buckets": 20,
"extended_statistics_ok": true,
"keyed": true,
"description": "Time (ms) that the main thread has been blocked on NPP_New in an IPC plugin"
},
"BLOCKED_ON_PLUGIN_STREAM_INIT_MS": {
"expires_in_version": "40",
"kind": "exponential",
"high": "10000",
"n_buckets": 20,
"extended_statistics_ok": true,
"keyed": true,
"description": "Time (ms) that the main thread has been blocked on NPP_NewStream in an IPC plugin"
},
"BLOCKED_ON_PLUGIN_INSTANCE_DESTROY_MS": {
"expires_in_version": "40",
"kind": "exponential",
"high": "10000",
"n_buckets": 20,
"extended_statistics_ok": true,
"keyed": true,
"description": "Time (ms) that the main thread has been blocked on NPP_Destroy in an IPC plugin"
},
"ONBEFOREUNLOAD_PROMPT_ACTION" : {
"expires_in_version": "45",
"kind": "enumerated",

21
toolkit/components/telemetry/Telemetry.h
View File

@ -89,6 +89,7 @@ template<TimerResolution res>
struct AccumulateDelta_impl
{
static void compute(ID id, TimeStamp start, TimeStamp end = TimeStamp::Now());
static void compute(ID id, const nsCString& key, TimeStamp start, TimeStamp end = TimeStamp::Now());
};
template<>
@ -97,6 +98,9 @@ struct AccumulateDelta_impl<Millisecond>
static void compute(ID id, TimeStamp start, TimeStamp end = TimeStamp::Now()) {
Accumulate(id, static_cast<uint32_t>((end - start).ToMilliseconds()));
}
static void compute(ID id, const nsCString& key, TimeStamp start, TimeStamp end = TimeStamp::Now()) {
Accumulate(id, key, static_cast<uint32_t>((end - start).ToMilliseconds()));
}
};
template<>
@ -105,6 +109,9 @@ struct AccumulateDelta_impl<Microsecond>
static void compute(ID id, TimeStamp start, TimeStamp end = TimeStamp::Now()) {
Accumulate(id, static_cast<uint32_t>((end - start).ToMicroseconds()));
}
static void compute(ID id, const nsCString& key, TimeStamp start, TimeStamp end = TimeStamp::Now()) {
Accumulate(id, key, static_cast<uint32_t>((end - start).ToMicroseconds()));
}
};
@ -117,12 +124,24 @@ public:
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
}
explicit AutoTimer(const nsCString& aKey, TimeStamp aStart = TimeStamp::Now() MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
: start(aStart)
, key(aKey)
{
MOZ_GUARD_OBJECT_NOTIFIER_INIT;
}
~AutoTimer() {
AccumulateDelta_impl<res>::compute(id, start);
if (key.IsEmpty()) {
AccumulateDelta_impl<res>::compute(id, start);
} else {
AccumulateDelta_impl<res>::compute(id, key, start);
}
}
private:
const TimeStamp start;
const nsCString key;
MOZ_DECL_USE_GUARD_OBJECT_NOTIFIER
};