Bug 976000: Add info to Telemetry.fileIOReports to differentiate between start/normal/shutdown I/O; r=froydnj

--HG--
extra : rebase_source : 3762a056a06e782648c27cd469ee5f639d500e22
This commit is contained in:
Aaron Klotz 2014-03-18 16:07:35 -06:00
parent 58aabd2c19
commit abca1db1d5
4 changed files with 103 additions and 28 deletions

View File

@ -165,9 +165,9 @@ nsAppStartup::Init()
os->AddObserver(this, "profile-change-teardown", true);
os->AddObserver(this, "xul-window-registered", true);
os->AddObserver(this, "xul-window-destroyed", true);
os->AddObserver(this, "xpcom-shutdown", true);
#if defined(XP_WIN)
os->AddObserver(this, "xpcom-shutdown", true);
os->AddObserver(this, "places-init-complete", true);
// This last event is only interesting to us for xperf-based measures
@ -695,6 +695,7 @@ nsAppStartup::Observe(nsISupports *aSubject,
ExitLastWindowClosingSurvivalArea();
} else if (!strcmp(aTopic, "sessionstore-windows-restored")) {
StartupTimeline::Record(StartupTimeline::SESSION_RESTORED);
Telemetry::LeavingStartupStage();
#if defined(XP_WIN)
if (mSessionWindowRestoredProbe) {
mSessionWindowRestoredProbe->Trigger();
@ -703,11 +704,14 @@ nsAppStartup::Observe(nsISupports *aSubject,
if (mPlacesInitCompleteProbe) {
mPlacesInitCompleteProbe->Trigger();
}
#endif //defined(XP_WIN)
} else if (!strcmp(aTopic, "xpcom-shutdown")) {
Telemetry::EnteringShutdownStage();
#if defined(XP_WIN)
if (mXPCOMShutdownProbe) {
mXPCOMShutdownProbe->Trigger();
}
#endif //defined(XP_WIN)
#endif // defined(XP_WIN)
} else {
NS_ERROR("Unexpected observer topic.");
}

View File

@ -291,7 +291,6 @@ class TelemetryIOInterposeObserver : public IOInterposeObserver
uint32_t stats; /** Number of stat operations */
double totalTime; /** Accumulated duration of all operations */
};
typedef nsBaseHashtableET<nsStringHashKey, FileStats> FileIOEntryType;
struct SafeDir {
SafeDir(const nsAString& aPath, const nsAString& aSubstName)
@ -327,6 +326,24 @@ public:
*/
void AddPath(const nsAString& aPath, const nsAString& aSubstName);
enum Stage
{
STAGE_STARTUP = 0,
STAGE_NORMAL,
STAGE_SHUTDOWN,
NUM_STAGES
};
/**
* Sets a new stage in the lifecycle of this process.
* @param aNewStage One of the STAGE_* enum values.
*/
inline void SetStage(Stage aNewStage)
{
MOZ_ASSERT(aNewStage != NUM_STAGES);
mCurStage = aNewStage;
}
/**
* Get size of hash table with file stats
*/
@ -347,10 +364,17 @@ public:
}
private:
struct FileStatsByStage
{
FileStats mStats[NUM_STAGES];
};
typedef nsBaseHashtableET<nsStringHashKey, FileStatsByStage> FileIOEntryType;
// Statistics for each filename
AutoHashtable<FileIOEntryType> mFileStats;
// Container for whitelisted directories
nsTArray<SafeDir> mSafeDirs;
Stage mCurStage;
/**
* Reflect a FileIOEntryType object to a Javascript property on obj with
@ -369,6 +393,7 @@ private:
};
TelemetryIOInterposeObserver::TelemetryIOInterposeObserver(nsIFile* aXreDir)
: mCurStage(STAGE_STARTUP)
{
nsAutoString xreDirPath;
nsresult rv = aXreDir->GetPath(xreDirPath);
@ -421,23 +446,24 @@ void TelemetryIOInterposeObserver::Observe(Observation& aOb)
// Create a new entry or retrieve the existing one
FileIOEntryType* entry = mFileStats.PutEntry(processedName);
if (entry) {
FileStats& stats = entry->mData.mStats[mCurStage];
// Update the statistics
entry->mData.totalTime += (double) aOb.Duration().ToMilliseconds();
stats.totalTime += (double) aOb.Duration().ToMilliseconds();
switch (aOb.ObservedOperation()) {
case OpCreateOrOpen:
entry->mData.creates += 1;
stats.creates++;
break;
case OpRead:
entry->mData.reads += 1;
stats.reads++;
break;
case OpWrite:
entry->mData.writes += 1;
stats.writes++;
break;
case OpFSync:
entry->mData.fsyncs += 1;
stats.fsyncs++;
break;
case OpStat:
entry->mData.stats += 1;
stats.stats++;
break;
default:
break;
@ -449,24 +475,39 @@ bool TelemetryIOInterposeObserver::ReflectFileStats(FileIOEntryType* entry,
JSContext *cx,
JS::Handle<JSObject*> obj)
{
// Let's not report arrays containing [0, 0, 0, 0, 0, 0]
if (entry->mData.totalTime == 0 && entry->mData.creates == 0 &&
entry->mData.reads == 0 && entry->mData.writes == 0 &&
entry->mData.fsyncs == 0 && entry->mData.stats == 0) {
return true;
JS::AutoValueArray<NUM_STAGES> stages(cx);
FileStatsByStage& statsByStage = entry->mData;
for (int s = STAGE_STARTUP; s < NUM_STAGES; ++s) {
FileStats& fileStats = statsByStage.mStats[s];
if (fileStats.totalTime == 0 && fileStats.creates == 0 &&
fileStats.reads == 0 && fileStats.writes == 0 &&
fileStats.fsyncs == 0 && fileStats.stats == 0) {
// Don't add an array that contains no information
stages[s].setNull();
continue;
}
// Array we want to report
JS::AutoValueArray<6> stats(cx);
stats[0].setNumber(fileStats.totalTime);
stats[1].setNumber(fileStats.creates);
stats[2].setNumber(fileStats.reads);
stats[3].setNumber(fileStats.writes);
stats[4].setNumber(fileStats.fsyncs);
stats[5].setNumber(fileStats.stats);
// Create jsStats as array of elements above
JS::RootedObject jsStats(cx, JS_NewArrayObject(cx, stats));
if (!jsStats) {
continue;
}
stages[s].setObject(*jsStats);
}
// Array we want to report
JS::AutoValueArray<6> stats(cx);
stats[0].setNumber(entry->mData.totalTime);
stats[1].setNumber(entry->mData.creates);
stats[2].setNumber(entry->mData.reads);
stats[3].setNumber(entry->mData.writes);
stats[4].setNumber(entry->mData.fsyncs);
stats[5].setNumber(entry->mData.stats);
// Create jsEntry as array of elements above
JS::RootedObject jsEntry(cx, JS_NewArrayObject(cx, stats));
JS::RootedObject jsEntry(cx, JS_NewArrayObject(cx, stages));
if (!jsEntry) {
return false;
}
@ -474,8 +515,8 @@ bool TelemetryIOInterposeObserver::ReflectFileStats(FileIOEntryType* entry,
// Add jsEntry to top-level dictionary
const nsAString& key = entry->GetKey();
return JS_DefineUCProperty(cx, obj, key.Data(), key.Length(),
OBJECT_TO_JSVAL(jsEntry), NULL, NULL,
JSPROP_ENUMERATE);
OBJECT_TO_JSVAL(jsEntry), nullptr, nullptr,
JSPROP_ENUMERATE | JSPROP_READONLY);
}
bool TelemetryIOInterposeObserver::ReflectIntoJS(JSContext *cx,
@ -2986,6 +3027,24 @@ SetProfileDir(nsIFile* aProfD)
sTelemetryIOObserver->AddPath(profDirPath, NS_LITERAL_STRING("{profile}"));
}
void
LeavingStartupStage()
{
if (!sTelemetryIOObserver) {
return;
}
sTelemetryIOObserver->SetStage(TelemetryIOInterposeObserver::STAGE_NORMAL);
}
void
EnteringShutdownStage()
{
if (!sTelemetryIOObserver) {
return;
}
sTelemetryIOObserver->SetStage(TelemetryIOInterposeObserver::STAGE_SHUTDOWN);
}
void
TimeHistogram::Add(PRIntervalTime aTime)
{

View File

@ -170,6 +170,16 @@ void InitIOReporting(nsIFile* aXreDir);
*/
void SetProfileDir(nsIFile* aProfD);
/**
* Called to inform Telemetry that startup has completed.
*/
void LeavingStartupStage();
/**
* Called to inform Telemetry that shutdown is commencing.
*/
void EnteringShutdownStage();
/**
* Thresholds for a statement to be considered slow, in milliseconds
*/

View File

@ -245,7 +245,9 @@ interface nsITelemetry : nsISupports
*
* The statistics are returned as an object whose propoerties are the names
* of the files that have been accessed and whose corresponding values are
* arrays of the form [total_time, #creates, #reads, #writes, #fsyncs, #stats]
* arrays of size three, representing startup, normal, and shutdown stages.
* Each stage's entry is either null or an array with the layout
* [total_time, #creates, #reads, #writes, #fsyncs, #stats]
*/
[implicit_jscontext]
readonly attribute jsval fileIOReports;