wine/gecko
0
0
Fork 0
mirror of https://gitlab.winehq.org/wine/wine-gecko.git synced 2024-09-13 09:24:08 -07:00
Code Issues Packages Projects Releases Wiki Activity

Bug 675737: Calculate time taken for by write/open/sync per db + main/other thread r=mak

Browse Source
This commit is contained in:
Taras Glek 2011-08-03 17:05:29 -07:00
parent 333edf60a8
commit 6769ff0594
2 changed files with 68 additions and 54 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

89
storage/src/TelemetryVFS.cpp
View File

@ -48,52 +48,58 @@ using namespace mozilla;
struct Histograms {
const char *name;
Telemetry::ID readB;
Telemetry::ID writeB;
Telemetry::ID syncMs;
const Telemetry::ID readB;
const Telemetry::ID writeB;
const Telemetry::ID readMS;
const Telemetry::ID writeMS;
const Telemetry::ID syncMS;
};
#define SQLITE_TELEMETRY(FILENAME, HGRAM) \
{ FILENAME, \
Telemetry::MOZ_SQLITE_ ## HGRAM ## _READ_B, \
Telemetry::MOZ_SQLITE_ ## HGRAM ## _WRITE_B, \
Telemetry::MOZ_SQLITE_ ## HGRAM ## _READ_MS, \
Telemetry::MOZ_SQLITE_ ## HGRAM ## _WRITE_MS, \
Telemetry::MOZ_SQLITE_ ## HGRAM ## _SYNC_MS \
}
Histograms gHistograms[] = {
{"places.sqlite",
Telemetry::MOZ_SQLITE_PLACES_READ_B,
Telemetry::MOZ_SQLITE_PLACES_WRITE_B,
Telemetry::MOZ_SQLITE_PLACES_SYNC },
{"urlclassifier3.sqlite",
Telemetry::MOZ_SQLITE_URLCLASSIFIER_READ_B,
Telemetry::MOZ_SQLITE_URLCLASSIFIER_WRITE_B,
Telemetry::MOZ_SQLITE_URLCLASSIFIER_SYNC },
{"cookies.sqlite",
Telemetry::MOZ_SQLITE_COOKIES_READ_B,
Telemetry::MOZ_SQLITE_COOKIES_WRITE_B,
Telemetry::MOZ_SQLITE_COOKIES_SYNC },
{NULL,
Telemetry::MOZ_SQLITE_OTHER_READ_B,
Telemetry::MOZ_SQLITE_OTHER_WRITE_B,
Telemetry::MOZ_SQLITE_OTHER_SYNC }
SQLITE_TELEMETRY("places.sqlite", PLACES),
SQLITE_TELEMETRY("urlclassifier3.sqlite", URLCLASSIFIER),
SQLITE_TELEMETRY("cookies.sqlite", COOKIES),
SQLITE_TELEMETRY(NULL, OTHER)
};
#undef SQLITE_TELEMETRY
/** RAII class for measuring how long io takes on/off main thread */
/** RAII class for measuring how long io takes on/off main thread
*/
class IOThreadAutoTimer {
public:
IOThreadAutoTimer(MOZILLA_GUARD_OBJECT_NOTIFIER_ONLY_PARAM)
: start(TimeStamp::Now())
/**
* IOThreadAutoTimer measures time spent in IO. Additionally it
* automatically determines whether IO is happening on the main
* thread and picks an appropriate histogram.
*
* @param id takes a telemetry histogram id. The id+1 must be an
* equivalent histogram for the main thread. Eg, MOZ_SQLITE_OPEN_MS
* is followed by MOZ_SQLITE_OPEN_MAIN_THREAD_MS.
*/
IOThreadAutoTimer(Telemetry::ID id)
: start(TimeStamp::Now()),
id(id)
{
MOZILLA_GUARD_OBJECT_NOTIFIER_INIT;
}
~IOThreadAutoTimer() {
Accumulate(NS_IsMainThread() ? Telemetry::MOZ_SQLITE_MAIN_THREAD_WAIT_MS
: Telemetry::MOZ_SQLITE_OTHER_THREAD_WAIT_MS
, (TimeStamp::Now() - start).ToMilliseconds());
PRUint32 mainThread = NS_IsMainThread() ? 1 : 0;
Telemetry::Accumulate(static_cast<Telemetry::ID>(id + mainThread),
(TimeStamp::Now() - start).ToMilliseconds());
}
private:
const TimeStamp start;
MOZILLA_DECL_USE_GUARD_OBJECT_NOTIFIER
const Telemetry::ID id;
};
struct telemetry_file {
@ -124,9 +130,8 @@ xClose(sqlite3_file *pFile)
int
xRead(sqlite3_file *pFile, void *zBuf, int iAmt, sqlite_int64 iOfst)
{
IOThreadAutoTimer ioTimer;
telemetry_file *p = (telemetry_file *)pFile;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_READ_MS> timer;
IOThreadAutoTimer ioTimer(p->histograms->readMS);
int rc;
rc = p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst);
// sqlite likes to read from empty files, this is normal, ignore it.
@ -141,9 +146,8 @@ xRead(sqlite3_file *pFile, void *zBuf, int iAmt, sqlite_int64 iOfst)
int
xWrite(sqlite3_file *pFile, const void *zBuf, int iAmt, sqlite_int64 iOfst)
{
IOThreadAutoTimer ioTimer;
telemetry_file *p = (telemetry_file *)pFile;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_WRITE_MS> timer;
IOThreadAutoTimer ioTimer(p->histograms->writeMS);
int rc;
rc = p->pReal->pMethods->xWrite(p->pReal, zBuf, iAmt, iOfst);
Telemetry::Accumulate(p->histograms->writeB, rc == SQLITE_OK ? iAmt : 0);
@ -156,10 +160,10 @@ xWrite(sqlite3_file *pFile, const void *zBuf, int iAmt, sqlite_int64 iOfst)
int
xTruncate(sqlite3_file *pFile, sqlite_int64 size)
{
IOThreadAutoTimer ioTimer;
IOThreadAutoTimer ioTimer(Telemetry::MOZ_SQLITE_TRUNCATE_MS);
telemetry_file *p = (telemetry_file *)pFile;
int rc;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_TRUNCATE> timer;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_TRUNCATE_MS> timer;
rc = p->pReal->pMethods->xTruncate(p->pReal, size);
return rc;
}
@ -170,12 +174,9 @@ xTruncate(sqlite3_file *pFile, sqlite_int64 size)
int
xSync(sqlite3_file *pFile, int flags)
{
IOThreadAutoTimer ioTimer;
telemetry_file *p = (telemetry_file *)pFile;
const TimeStamp start = TimeStamp::Now();
int rc = p->pReal->pMethods->xSync(p->pReal, flags);
Telemetry::Accumulate(p->histograms->syncMs, static_cast<PRUint32>((TimeStamp::Now() - start).ToMilliseconds()));
return rc;
IOThreadAutoTimer ioTimer(p->histograms->syncMS);
return p->pReal->pMethods->xSync(p->pReal, flags);
}
/*
@ -297,8 +298,8 @@ int
xOpen(sqlite3_vfs* vfs, const char *zName, sqlite3_file* pFile,
int flags, int *pOutFlags)
{
IOThreadAutoTimer ioTimer;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_OPEN> timer;
IOThreadAutoTimer ioTimer(Telemetry::MOZ_SQLITE_OPEN_MS);
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_OPEN_MS> timer;
sqlite3_vfs *orig_vfs = static_cast<sqlite3_vfs*>(vfs->pAppData);
int rc;
telemetry_file *p = (telemetry_file *)pFile;

33
toolkit/components/telemetry/TelemetryHistograms.h
View File

@ -118,28 +118,41 @@ HTTP_HISTOGRAMS(SUB, "subitem: ")
#undef HTTP_HISTOGRAMS
HISTOGRAM(FIND_PLUGINS, 1, 3000, 10, EXPONENTIAL, "Time spent scanning filesystem for plugins (ms)")
HISTOGRAM(CHECK_JAVA_ENABLED, 1, 3000, 10, EXPONENTIAL, "Time spent checking if Java is enabled (ms)")
HISTOGRAM(MOZ_SQLITE_OPEN, 1, 3000, 10, EXPONENTIAL, "Time spent on SQLite open() (ms)")
HISTOGRAM(MOZ_SQLITE_READ_MS, 1, 3000, 10, EXPONENTIAL, "Time spent on SQLite read() (ms)")
/* Define 2 histograms: MOZ_SQLITE_(NAME)_MS and
* MOZ_SQLITE_(NAME)_MAIN_THREAD_MS. These are meant to be used by
* IOThreadAutoTimer which relies on _MAIN_THREAD_MS histogram being
* "+ 1" away from MOZ_SQLITE_(NAME)_MS.
*/
#define SQLITE_TIME_SPENT(NAME, DESC) \
HISTOGRAM(MOZ_SQLITE_ ## NAME ## _MS, 1, 3000, 10, EXPONENTIAL, DESC) \
HISTOGRAM(MOZ_SQLITE_ ## NAME ## _MAIN_THREAD_MS, 1, 3000, 10, EXPONENTIAL, DESC)
#define SQLITE_TIME_PER_FILE(NAME, DESC) \
SQLITE_TIME_SPENT(OTHER_ ## NAME, DESC) \
SQLITE_TIME_SPENT(PLACES_ ## NAME, DESC) \
SQLITE_TIME_SPENT(COOKIES_ ## NAME, DESC) \
SQLITE_TIME_SPENT(URLCLASSIFIER_ ## NAME, DESC)
SQLITE_TIME_SPENT(OPEN, "Time spent on SQLite open() (ms)")
SQLITE_TIME_SPENT(TRUNCATE, "Time spent on SQLite truncate() (ms)")
SQLITE_TIME_PER_FILE(READ, "Time spent on SQLite read() (ms)")
SQLITE_TIME_PER_FILE(WRITE, "Time spent on SQLite write() (ms)")
SQLITE_TIME_PER_FILE(SYNC, "Time spent on SQLite fsync() (ms)")
#undef SQLITE_TIME_PER_FILE
#undef SQLITE_TIME_SPENT
HISTOGRAM(MOZ_SQLITE_OTHER_READ_B, 1, 32768, 3, LINEAR, "SQLite read() (bytes)")
HISTOGRAM(MOZ_SQLITE_PLACES_READ_B, 1, 32768, 3, LINEAR, "SQLite read() (bytes)")
HISTOGRAM(MOZ_SQLITE_COOKIES_READ_B, 1, 32768, 3, LINEAR, "SQLite read() (bytes)")
HISTOGRAM(MOZ_SQLITE_URLCLASSIFIER_READ_B, 1, 32768, 3, LINEAR, "SQLite read() (bytes)")
HISTOGRAM(MOZ_SQLITE_WRITE_MS, 1, 3000, 10, EXPONENTIAL, "Time spent on SQLite write() (ms)")
HISTOGRAM(MOZ_SQLITE_PLACES_WRITE_B, 1, 32768, 3, LINEAR, "SQLite write (bytes)")
HISTOGRAM(MOZ_SQLITE_COOKIES_WRITE_B, 1, 32768, 3, LINEAR, "SQLite write (bytes)")
HISTOGRAM(MOZ_SQLITE_URLCLASSIFIER_WRITE_B, 1, 32768, 3, LINEAR, "SQLite write (bytes)")
HISTOGRAM(MOZ_SQLITE_OTHER_WRITE_B, 1, 32768, 3, LINEAR, "SQLite write (bytes)")
HISTOGRAM(MOZ_SQLITE_TRUNCATE, 1, 3000, 10, EXPONENTIAL, "Time spent on SQLite truncate() (ms)")
HISTOGRAM(MOZ_SQLITE_PLACES_SYNC, 1, 10000, 10, EXPONENTIAL, "Time spent on SQLite fsync() (ms)")
HISTOGRAM(MOZ_SQLITE_COOKIES_SYNC, 1, 10000, 10, EXPONENTIAL, "Time spent on SQLite fsync() (ms)")
HISTOGRAM(MOZ_SQLITE_URLCLASSIFIER_SYNC, 1, 10000, 10, EXPONENTIAL, "Time spent on SQLite fsync() (ms)")
HISTOGRAM(MOZ_SQLITE_OTHER_SYNC, 1, 10000, 10, EXPONENTIAL, "Time spent on SQLite fsync() (ms)")
HISTOGRAM(STARTUP_MEASUREMENT_ERRORS, 1, 3, 4, LINEAR, "Flags errors in startup calculation()")
HISTOGRAM(NETWORK_DISK_CACHE_OPEN, 1, 10000, 10, EXPONENTIAL, "Time spent opening disk cache (ms)")
HISTOGRAM(NETWORK_DISK_CACHE_TRASHRENAME, 1, 10000, 10, EXPONENTIAL, "Time spent renaming bad Cache to Cache.Trash (ms)")
HISTOGRAM(NETWORK_DISK_CACHE_DELETEDIR, 1, 10000, 10, EXPONENTIAL, "Time spent deleting disk cache (ms)")
HISTOGRAM(MOZ_SQLITE_MAIN_THREAD_WAIT_MS, 1, 3000, 10, EXPONENTIAL, "Time spent waiting on SQLite IO on main thread (ms)")
HISTOGRAM(MOZ_SQLITE_OTHER_THREAD_WAIT_MS, 1, 3000, 10, EXPONENTIAL, "Time spent waiting on SQLite IO off main thread (ms)")
/**
* Places telemetry.