Foundry376/Mailspring
1
1
Fork 0
mirror of https://github.com/Foundry376/Mailspring.git synced 2025-09-15 17:15:01 +08:00
Code Issues Projects Releases Packages Wiki Activity

[client-app] Improve logging for queries

Browse source 
Summary:
This commit makes a few changes to how we log database queries:

- We log queries in 2 different places now:
  - When `DatabaseStore._executeLocally` takes longer than 100ms. This might be due to the actual db operation taking long, or it might be due to our retry logic, or potentially other factors.
  - When the actual raw database operation takes more than 100ms.
- When raw database queries take more than 100ms, we log out the query plan if it is a `SELECT` query and we are in dev mode.
- If `DEBUG_TO_LOG` is true, we always log all queries (including background queries)

Test Plan: manual

Reviewers: mark, halla, evan

Reviewed By: halla, evan

Differential Revision: https://phab.nylas.com/D4288
This commit is contained in:
Juan Tejada 2017-03-29 12:08:02 -07:00
parent d26a3e7448
commit ec51e982eb
1 changed files with 22 additions and 17 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

39
packages/client-app/src/flux/stores/database-store.es6
View file

@ -294,7 +294,7 @@ class DatabaseStore extends NylasStore {
//
// If a query is made before the database has been opened, the query will be
// held in a queue and run / resolved when the database is ready.
_query(query, values = [], background = false, logQueryPlanDebugOutput = true) {
_query(query, values = [], background = false) {
return new Promise(async (resolve, reject) => {
if (!this._open) {
this._waiting.push(() => this._query(query, values).then(resolve, reject));
@ -313,26 +313,13 @@ class DatabaseStore extends NylasStore {
}
});
if (query.startsWith(`SELECT `) && DEBUG_QUERY_PLANS) {
const plan = this._db.prepare(`EXPLAIN QUERY PLAN ${query}`).all(values);
const planString = `${plan.map(row => row.detail).join('\n')} for ${query}`;
const quiet = ['ThreadCounts', 'ThreadSearch', 'ContactSearch', 'COVERING INDEX'];
if (planString.includes('SCAN') &&
!quiet.find(str => planString.includes(str)) &&
logQueryPlanDebugOutput) {
console.log("Consider setting the .background() flag on this query to avoid blocking the event loop:")
this._prettyConsoleLog(planString);
}
}
const start = Date.now();
if (!background) {
const results = await this._executeLocally(query, values);
const msec = Date.now() - start;
if ((msec > 100) || DEBUG_TO_LOG) {
this._prettyConsoleLog(`${msec}msec: ${query}`);
if (msec > 100) {
this._prettyConsoleLog(`DatabaseStore._executeLocally took more than 100ms - ${msec}msec: ${query}`);
}
resolve(results);
} else {
@ -344,7 +331,7 @@ class DatabaseStore extends NylasStore {
}
this._executeInBackground(query, values).then(({results, backgroundTime}) => {
const msec = Date.now() - start;
if ((msec > 100) || DEBUG_TO_LOG) {
if (msec > 100 || DEBUG_TO_LOG) {
const msgPrefix = msec > 100 ? 'DatabaseStore._executeInBackground took more than 100ms - ' : ''
this._prettyConsoleLog(`${msgPrefix}${msec}msec (${backgroundTime}msec in background): ${query}`);
}
@ -390,7 +377,25 @@ class DatabaseStore extends NylasStore {
stmt = this._db.prepare(query);
this._preparedStatementCache.set(query, stmt)
}
const start = Date.now();
results = stmt[fn](values);
const msec = Date.now() - start
if (msec > 100 || DEBUG_TO_LOG) {
const msgPrefix = msec > 100 ? 'DatabaseStore: query took more than 100ms - ' : ''
if (query.startsWith(`SELECT `) && DEBUG_QUERY_PLANS) {
const plan = this._db.prepare(`EXPLAIN QUERY PLAN ${query}`).all(values);
const planString = `${plan.map(row => row.detail).join('\n')} for ${query}`;
const quiet = ['ThreadCounts', 'ThreadSearch', 'ContactSearch', 'COVERING INDEX'];
if (!quiet.find(str => planString.includes(str))) {
this._prettyConsoleLog(`${msgPrefix}${msec}msec: ${planString}`);
}
} else {
this._prettyConsoleLog(`${msgPrefix}${msec}msec: ${query}`);
}
}
} catch (err) {
const errString = err.toString()