Bug 673727: Report sqlite waiting on/off main thread via telemetry r=mak

This commit is contained in:
Taras Glek 2011-07-26 15:06:34 -07:00
parent 3fcab63ef0
commit 6c0ccfa697
2 changed files with 46 additions and 17 deletions

View File

@ -37,9 +37,10 @@
*
* ***** END LICENSE BLOCK ***** */
#include <string.h>
#include "mozilla/Telemetry.h"
#include "sqlite3.h"
#include <string.h>
#include "nsThreadUtils.h"
namespace {
@ -74,6 +75,27 @@ Histograms gHistograms[] = {
Telemetry::MOZ_SQLITE_OTHER_SYNC }
};
/** 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())
{
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());
}
private:
const TimeStamp start;
MOZILLA_DECL_USE_GUARD_OBJECT_NOTIFIER
};
struct telemetry_file {
sqlite3_file base; // Base class. Must be first
Histograms *histograms; // histograms pertaining to this file
@ -102,6 +124,7 @@ 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;
int rc;
@ -118,6 +141,7 @@ 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;
int rc;
@ -132,6 +156,7 @@ xWrite(sqlite3_file *pFile, const void *zBuf, int iAmt, sqlite_int64 iOfst)
int
xTruncate(sqlite3_file *pFile, sqlite_int64 size)
{
IOThreadAutoTimer ioTimer;
telemetry_file *p = (telemetry_file *)pFile;
int rc;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_TRUNCATE> timer;
@ -145,6 +170,7 @@ 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);
@ -271,6 +297,7 @@ int
xOpen(sqlite3_vfs* vfs, const char *zName, sqlite3_file* pFile,
int flags, int *pOutFlags)
{
IOThreadAutoTimer ioTimer;
Telemetry::AutoTimer<Telemetry::MOZ_SQLITE_OPEN> timer;
sqlite3_vfs *orig_vfs = static_cast<sqlite3_vfs*>(vfs->pAppData);
int rc;

View File

@ -103,21 +103,23 @@ 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)")
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(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)")
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(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)")