[client-app] More defensive error handling to prevent sync from halting

Summary:
This commit adds error handling to the sync-loop's `onSyncError` and
`scheduleNextSync`.

These functions generally don't fail, as they are in the `catch` and
`finally` blocks respectively of the sync loop. But as we've seen in
D4152, the datbase can sometime error if it's in a bad state. If it
errors inside these functions, we will never schedule the next run of
the sync loop.

Depends on D4152

Test Plan: manual

Reviewers: evan, spang, mark, halla

Reviewed By: halla

Differential Revision: https://phab.nylas.com/D4153
This commit is contained in:
Juan Tejada 2017-03-09 08:08:39 -08:00
parent d2cd0db335
commit d24fc9a235

View file

@ -25,7 +25,6 @@ const {SYNC_STATE_RUNNING, SYNC_STATE_AUTH_FAILED, SYNC_STATE_ERROR} = Account
const AC_SYNC_LOOP_INTERVAL_MS = 10 * 1000 // 10 sec const AC_SYNC_LOOP_INTERVAL_MS = 10 * 1000 // 10 sec
const BATTERY_SYNC_LOOP_INTERVAL_MS = 5 * 60 * 1000 // 5 min const BATTERY_SYNC_LOOP_INTERVAL_MS = 5 * 60 * 1000 // 5 min
const MAX_SYNC_BACKOFF_MS = 5 * 60 * 1000 // 5 min const MAX_SYNC_BACKOFF_MS = 5 * 60 * 1000 // 5 min
const PERMANENT_ERROR_RETRY_BACKOFF_MS = 60 * 1000 // 1 min
class SyncWorker { class SyncWorker {
constructor(account, db, parentManager) { constructor(account, db, parentManager) {
@ -294,56 +293,62 @@ class SyncWorker {
} }
async _onSyncError(error) { async _onSyncError(error) {
this._clearConnections(); try {
this._logger.error(`🔃 SyncWorker: Errored while syncing account`, error) this._clearConnections();
this._logger.error(`🔃 SyncWorker: Errored while syncing account`, error)
// Check if we encountered an expired token error. // Check if we encountered an expired token error.
// We try to refresh Google OAuth2 access tokens in advance, but sometimes // We try to refresh Google OAuth2 access tokens in advance, but sometimes
// it doesn't work (e.g. the token expires during the sync loop). In this // it doesn't work (e.g. the token expires during the sync loop). In this
// case, we need to immediately restart the sync loop & refresh the token. // case, we need to immediately restart the sync loop & refresh the token.
// We don't want to save the error to the account in case refreshing the // We don't want to save the error to the account in case refreshing the
// token fixes the issue. // token fixes the issue.
// //
// These error messages look like "Error: Invalid credentials (Failure)" // These error messages look like "Error: Invalid credentials (Failure)"
const isExpiredTokenError = ( const isExpiredTokenError = (
this._account.provider === "gmail" && this._account.provider === "gmail" &&
error instanceof IMAPErrors.IMAPAuthenticationError && error instanceof IMAPErrors.IMAPAuthenticationError &&
/invalid credentials/i.test(error.message) /invalid credentials/i.test(error.message)
) )
if (isExpiredTokenError) { if (isExpiredTokenError) {
this._requireTokenRefresh = true this._requireTokenRefresh = true
return return
}
// Check if we've encountered a retryable/network error.
// If so, we don't want to save the error to the account, which will cause
// a red box to show up.
if (error instanceof IMAPErrors.RetryableError) {
this._retryScheduler.nextDelay()
return
}
// If we don't encounter consecutive RetryableErrors, reset the exponential
// backoff
this._retryScheduler.reset()
// Update account error state
const errorJSON = error.toJSON()
const fingerprint = ["{{ default }}", "sync loop", error.message];
NylasEnv.reportError(error, {fingerprint,
rateLimit: {
ratePerHour: 30,
key: `SyncError:SyncLoop:${error.message}`,
},
});
const isAuthError = error instanceof IMAPErrors.IMAPAuthenticationError
const accountSyncState = isAuthError ? SYNC_STATE_AUTH_FAILED : SYNC_STATE_ERROR;
// TODO this is currently a hack to keep N1's account in sync and notify of
// sync errors. This should go away when we merge the databases
Actions.updateAccount(this._account.id, {syncState: accountSyncState, syncError: errorJSON})
this._account.syncError = errorJSON
await this._account.save()
} catch (err) {
this._logger.error(`🔃 SyncWorker: Errored while handling error`, error)
err.message = `Error while handling sync loop error: ${err.message}`
NylasEnv.reportError(err)
} }
// Check if we've encountered a retryable/network error.
// If so, we don't want to save the error to the account, which will cause
// a red box to show up.
if (error instanceof IMAPErrors.RetryableError) {
this._retryScheduler.nextDelay()
return
}
// If we don't encounter consecutive RetryableErrors, reset the exponential
// backoff
this._retryScheduler.reset()
// Update account error state
const errorJSON = error.toJSON()
const fingerprint = ["{{ default }}", "sync loop", error.message];
NylasEnv.reportError(error, {fingerprint,
rateLimit: {
ratePerHour: 30,
key: `SyncError:SyncLoop:${error.message}`,
},
});
const isAuthError = error instanceof IMAPErrors.IMAPAuthenticationError
const accountSyncState = isAuthError ? SYNC_STATE_AUTH_FAILED : SYNC_STATE_ERROR;
// TODO this is currently a hack to keep N1's account in sync and notify of
// sync errors. This should go away when we merge the databases
Actions.updateAccount(this._account.id, {syncState: accountSyncState, syncError: errorJSON})
this._account.syncError = errorJSON
await this._account.save()
} }
async _onSyncDidComplete() { async _onSyncDidComplete() {
@ -372,50 +377,58 @@ class SyncWorker {
} }
async _scheduleNextSync(error) { async _scheduleNextSync(error) {
if (this._stopped) { return; } let reason;
const {Folder} = this._db;
const folders = await Folder.findAll();
const moreToSync = folders.some((f) => !f.isSyncComplete())
let interval; let interval;
if (error != null) { try {
if (error instanceof IMAPErrors.RetryableError) { if (this._stopped) { return; }
interval = this._retryScheduler.currentDelay(); const {Folder} = this._db;
const folders = await Folder.findAll();
const moreToSync = folders.some((f) => !f.isSyncComplete())
if (error != null) {
if (error instanceof IMAPErrors.RetryableError) {
interval = this._retryScheduler.currentDelay();
} else {
interval = AC_SYNC_LOOP_INTERVAL_MS;
}
} else { } else {
interval = PERMANENT_ERROR_RETRY_BACKOFF_MS; const shouldSyncImmediately = (
moreToSync ||
this._interrupted ||
this._requireTokenRefresh
)
if (shouldSyncImmediately) {
interval = 1;
} else if (BatteryStatusManager.isBatteryCharging()) {
interval = AC_SYNC_LOOP_INTERVAL_MS;
} else {
interval = BATTERY_SYNC_LOOP_INTERVAL_MS;
}
} }
} else {
const shouldSyncImmediately = ( reason = 'Normal schedule'
moreToSync || if (error != null) {
this._interrupted || reason = `Sync errored: ${error.message}`
this._requireTokenRefresh } else if (this._interrupted) {
) reason = `Sync interrupted and restarted. Interrupt reason: ${reason}`
if (shouldSyncImmediately) { } else if (moreToSync) {
interval = 1; reason = `More to sync`
} else if (BatteryStatusManager.isBatteryCharging()) {
interval = AC_SYNC_LOOP_INTERVAL_MS;
} else {
interval = BATTERY_SYNC_LOOP_INTERVAL_MS;
} }
} catch (err) {
this._logger.error(`🔃 SyncWorker: Errored while scheduling next sync`, err)
err.message = `Error while scheduling next sync: ${err.message}`
NylasEnv.reportError(err)
interval = AC_SYNC_LOOP_INTERVAL_MS
reason = 'Errored while while scheduling next sync'
} finally {
const nextSyncIn = Math.max(1, this._lastSyncTime + interval - Date.now())
this._logger.log(`🔃 🔜 in ${nextSyncIn}ms - Reason: ${reason}`)
this._syncTimer = setTimeout(() => {
this.syncNow({reason});
}, nextSyncIn);
} }
let reason = "Scheduled"
if (error != null) {
reason = `Sync errored: ${error.message}`
} else if (this._interrupted) {
reason = `Sync interrupted and restarted. Interrupt reason: ${reason}`
} else if (moreToSync) {
reason = "More to sync"
}
const nextSyncIn = Math.max(1, this._lastSyncTime + interval - Date.now())
this._logger.log(`🔃 🔜 in ${nextSyncIn}ms - Reason: ${reason}`)
this._syncTimer = setTimeout(() => {
this.syncNow({reason});
}, nextSyncIn);
} }
async _runTask(task) { async _runTask(task) {