Arsharth/hydrogen-web
1
0
Fork 0
forked from mystiq/hydrogen-web
Code Issues Pull requests Projects Releases Packages Wiki Activity

Merge pull request #500 from vector-im/bwindels/idb-write-logging

Browse source 
IDB write error logging
This commit is contained in:
Bruno Windels 2021-09-17 18:37:55 +02:00 committed by GitHub
commit 4759b44233
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
22 changed files with 200 additions and 88 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

8
src/domain/SessionPickerViewModel.js
View file

@ -150,7 +150,9 @@ export class SessionPickerViewModel extends ViewModel {
async _exportData(id) {
const sessionInfo = await this.platform.sessionInfoStorage.get(id);
const stores = await this.platform.storageFactory.export(id);
const stores = await this.logger.run("export", log => {
return this.platform.storageFactory.export(id, log);
});
const data = {sessionInfo, stores};
return data;
}
@ -161,7 +163,9 @@ export class SessionPickerViewModel extends ViewModel {
const {sessionInfo} = data;
sessionInfo.comment = `Imported on ${new Date().toLocaleString()} from id ${sessionInfo.id}.`;
sessionInfo.id = this._createSessionContainer().createNewSessionId();
await this.platform.storageFactory.import(sessionInfo.id, data.stores);
await this.logger.run("import", log => {
return this.platform.storageFactory.import(sessionInfo.id, data.stores, log);
});
await this.platform.sessionInfoStorage.add(sessionInfo);
this._sessions.set(new SessionItemViewModel(sessionInfo, this));
} catch (err) {

14
src/logging/LogItem.js
View file

@ -43,12 +43,16 @@ export class LogItem {
/** logs a reference to a different log item, usually obtained from runDetached.
This is useful if the referenced operation can't be awaited. */
refDetached(logItem, logLevel = null) {
if (!logItem._values.refId) {
logItem.set("refId", this._logger._createRefId());
}
logItem.ensureRefId();
return this.log({ref: logItem._values.refId}, logLevel);
}
ensureRefId() {
if (!this._values.refId) {
this.set("refId", this._logger._createRefId());
}
}
/**
* Creates a new child item and runs it in `callback`.
*/
@ -231,4 +235,8 @@ export class LogItem {
this._children.push(item);
return item;
}
get logger() {
return this._logger;
}
}

10
src/matrix/Sync.js
View file

@ -296,14 +296,10 @@ export class Sync {
// avoid corrupting state by only
// storing the sync up till the point
// the exception occurred
try {
syncTxn.abort();
} catch (abortErr) {
log.set("couldNotAbortTxn", true);
}
throw err;
syncTxn.abort(log);
throw syncTxn.getCause(err);
}
await syncTxn.complete();
await syncTxn.complete(log);
}
_afterSync(sessionState, inviteStates, roomStates, archivedRoomStates, log) {

2
src/matrix/room/timeline/persistence/SyncWriter.js
View file

@ -162,7 +162,7 @@ export class SyncWriter {
storageEntry.displayName = member.displayName;
storageEntry.avatarUrl = member.avatarUrl;
}
txn.timelineEvents.insert(storageEntry);
txn.timelineEvents.insert(storageEntry, log);
const entry = new EventEntry(storageEntry, this._fragmentIdComparer);
entries.push(entry);
const updatedRelationTargetEntries = await this._relationWriter.writeRelation(entry, txn, log);

15
src/matrix/storage/idb/Storage.ts
View file

@ -17,20 +17,23 @@ limitations under the License.
import {Transaction} from "./Transaction";
import { STORE_NAMES, StoreNames, StorageError } from "../common";
import { reqAsPromise } from "./utils";
import { BaseLogger } from "../../../logging/BaseLogger.js";
const WEBKITEARLYCLOSETXNBUG_BOGUS_KEY = "782rh281re38-boguskey";
export class Storage {
private _db: IDBDatabase;
private _hasWebkitEarlyCloseTxnBug: boolean;
private _IDBKeyRange: typeof IDBKeyRange
storeNames: typeof StoreNames;
readonly logger: BaseLogger;
readonly IDBKeyRange: typeof IDBKeyRange;
readonly storeNames: typeof StoreNames;
constructor(idbDatabase: IDBDatabase, _IDBKeyRange: typeof IDBKeyRange, hasWebkitEarlyCloseTxnBug: boolean) {
constructor(idbDatabase: IDBDatabase, _IDBKeyRange: typeof IDBKeyRange, hasWebkitEarlyCloseTxnBug: boolean, logger: BaseLogger) {
this._db = idbDatabase;
this._IDBKeyRange = _IDBKeyRange;
this.IDBKeyRange = _IDBKeyRange;
this._hasWebkitEarlyCloseTxnBug = hasWebkitEarlyCloseTxnBug;
this.storeNames = StoreNames;
this.logger = logger;
}
_validateStoreNames(storeNames: StoreNames[]): void {
@ -49,7 +52,7 @@ export class Storage {
if (this._hasWebkitEarlyCloseTxnBug) {
await reqAsPromise(txn.objectStore(storeNames[0]).get(WEBKITEARLYCLOSETXNBUG_BOGUS_KEY));
}
return new Transaction(txn, storeNames, this._IDBKeyRange);
return new Transaction(txn, storeNames, this);
} catch(err) {
throw new StorageError("readTxn failed", err);
}
@ -64,7 +67,7 @@ export class Storage {
if (this._hasWebkitEarlyCloseTxnBug) {
await reqAsPromise(txn.objectStore(storeNames[0]).get(WEBKITEARLYCLOSETXNBUG_BOGUS_KEY));
}
return new Transaction(txn, storeNames, this._IDBKeyRange);
return new Transaction(txn, storeNames, this);
} catch(err) {
throw new StorageError("readWriteTxn failed", err);
}

17
src/matrix/storage/idb/StorageFactory.ts
View file

@ -20,9 +20,10 @@ import { exportSession, importSession, Export } from "./export";
import { schema } from "./schema";
import { detectWebkitEarlyCloseTxnBug } from "./quirks";
import { BaseLogger } from "../../../logging/BaseLogger.js";
import { LogItem } from "../../../logging/LogItem.js";
const sessionName = (sessionId: string) => `hydrogen_session_${sessionId}`;
const openDatabaseWithSessionId = function(sessionId: string, idbFactory: IDBFactory, log?: BaseLogger) {
const openDatabaseWithSessionId = function(sessionId: string, idbFactory: IDBFactory, log: LogItem) {
const create = (db, txn, oldVersion, version) => createStores(db, txn, oldVersion, version, log);
return openDatabase(sessionName(sessionId), create, schema.length, idbFactory);
}
@ -59,7 +60,7 @@ export class StorageFactory {
this._IDBKeyRange = _IDBKeyRange;
}
async create(sessionId: string, log?: BaseLogger): Promise<Storage> {
async create(sessionId: string, log: LogItem): Promise<Storage> {
await this._serviceWorkerHandler?.preventConcurrentSessionAccess(sessionId);
requestPersistedStorage().then(persisted => {
// Firefox lies here though, and returns true even if the user denied the request
@ -70,7 +71,7 @@ export class StorageFactory {
const hasWebkitEarlyCloseTxnBug = await detectWebkitEarlyCloseTxnBug(this._idbFactory);
const db = await openDatabaseWithSessionId(sessionId, this._idbFactory, log);
return new Storage(db, this._IDBKeyRange, hasWebkitEarlyCloseTxnBug);
return new Storage(db, this._IDBKeyRange, hasWebkitEarlyCloseTxnBug, log.logger);
}
delete(sessionId: string): Promise<IDBDatabase> {
@ -79,18 +80,18 @@ export class StorageFactory {
return reqAsPromise(req);
}
async export(sessionId: string): Promise<Export> {
const db = await openDatabaseWithSessionId(sessionId, this._idbFactory);
async export(sessionId: string, log: LogItem): Promise<Export> {
const db = await openDatabaseWithSessionId(sessionId, this._idbFactory, log);
return await exportSession(db);
}
async import(sessionId: string, data: Export): Promise<void> {
const db = await openDatabaseWithSessionId(sessionId, this._idbFactory);
async import(sessionId: string, data: Export, log: LogItem): Promise<void> {
const db = await openDatabaseWithSessionId(sessionId, this._idbFactory, log);
return await importSession(db, data);
}
}
async function createStores(db: IDBDatabase, txn: IDBTransaction, oldVersion: number | null, version: number, log?: BaseLogger): Promise<void> {
async function createStores(db: IDBDatabase, txn: IDBTransaction, oldVersion: number | null, version: number, log: LogItem): Promise<void> {
const startIdx = oldVersion || 0;
return log.wrap({l: "storage migration", oldVersion, version}, async log => {
for(let i = startIdx; i < version; ++i) {

49
src/matrix/storage/idb/Store.ts
View file

@ -18,6 +18,7 @@ import {QueryTarget, IDBQuery} from "./QueryTarget";
import {IDBRequestAttemptError} from "./error";
import {reqAsPromise} from "./utils";
import {Transaction} from "./Transaction";
import {LogItem} from "../../../logging/LogItem.js";
const LOG_REQUESTS = false;
@ -148,7 +149,7 @@ export class Store<T> extends QueryTarget<T> {
return new QueryTarget<T>(new QueryTargetWrapper<T>(this._idbStore.index(indexName)));
}
put(value: T): void {
put(value: T, log?: LogItem): void {
// If this request fails, the error will bubble up to the transaction and abort it,
// which is the behaviour we want. Therefore, it is ok to not create a promise for this
// request and await it.
@ -159,16 +160,52 @@ export class Store<T> extends QueryTarget<T> {
//
// Note that this can still throw synchronously, like it does for TransactionInactiveError,
// see https://www.w3.org/TR/IndexedDB-2/#transaction-lifetime-concept
this._idbStore.put(value);
const request = this._idbStore.put(value);
this._prepareErrorLog(request, log, "put", undefined, value);
}
add(value: T): void {
add(value: T, log?: LogItem): void {
// ok to not monitor result of request, see comment in `put`.
this._idbStore.add(value);
const request = this._idbStore.add(value);
this._prepareErrorLog(request, log, "add", undefined, value);
}
delete(keyOrKeyRange: IDBValidKey | IDBKeyRange): Promise<undefined> {
delete(keyOrKeyRange: IDBValidKey | IDBKeyRange, log?: LogItem): void {
// ok to not monitor result of request, see comment in `put`.
return reqAsPromise(this._idbStore.delete(keyOrKeyRange));
const request = this._idbStore.delete(keyOrKeyRange);
this._prepareErrorLog(request, log, "delete", keyOrKeyRange, undefined);
}
private _prepareErrorLog(request: IDBRequest, log: LogItem | undefined, operationName: string, key: IDBValidKey | IDBKeyRange | undefined, value: T | undefined) {
if (log) {
log.ensureRefId();
}
reqAsPromise(request).catch(err => {
try {
if (!key && value) {
key = this._getKey(value);
}
} catch {
key = "getKey failed";
}
this._transaction.addWriteError(err, log, operationName, key);
});
}
private _getKey(value: T): IDBValidKey {
const {keyPath} = this._idbStore;
if (Array.isArray(keyPath)) {
let field: any = value;
for (const part of keyPath) {
if (typeof field === "object") {
field = field[part];
} else {
break;
}
}
return field as IDBValidKey;
} else {
return value[keyPath] as IDBValidKey;
}
}
}

90
src/matrix/storage/idb/Transaction.ts
View file

@ -18,6 +18,7 @@ import {StoreNames} from "../common";
import {txnAsPromise} from "./utils";
import {StorageError} from "../common";
import {Store} from "./Store";
import {Storage} from "./Storage";
import {SessionStore} from "./stores/SessionStore";
import {RoomSummaryStore} from "./stores/RoomSummaryStore";
import {InviteStore} from "./stores/InviteStore";
@ -35,18 +36,39 @@ import {OutboundGroupSessionStore} from "./stores/OutboundGroupSessionStore";
import {GroupSessionDecryptionStore} from "./stores/GroupSessionDecryptionStore";
import {OperationStore} from "./stores/OperationStore";
import {AccountDataStore} from "./stores/AccountDataStore";
import {LogItem} from "../../../logging/LogItem.js";
import {BaseLogger} from "../../../logging/BaseLogger.js";
class WriteErrorInfo {
constructor(
public readonly error: StorageError,
public readonly refItem: LogItem | undefined,
public readonly operationName: string,
public readonly key: IDBValidKey | IDBKeyRange | undefined,
) {}
}
export class Transaction {
private _txn: IDBTransaction;
private _allowedStoreNames: StoreNames[];
private _stores: { [storeName in StoreNames]?: any };
private _storage: Storage;
private _writeErrors: WriteErrorInfo[];
constructor(txn: IDBTransaction, allowedStoreNames: StoreNames[], IDBKeyRange) {
constructor(txn: IDBTransaction, allowedStoreNames: StoreNames[], storage: Storage) {
this._txn = txn;
this._allowedStoreNames = allowedStoreNames;
this._stores = {};
// @ts-ignore
this.IDBKeyRange = IDBKeyRange;
this._storage = storage;
this._writeErrors = [];
}
get IDBKeyRange(): typeof IDBKeyRange {
return this._storage.IDBKeyRange;
}
get logger(): BaseLogger {
return this._storage.logger;
}
_idbStore(name: StoreNames): Store<any> {
@ -137,12 +159,66 @@ export class Transaction {
return this._store(StoreNames.accountData, idbStore => new AccountDataStore(idbStore));
}
complete(): Promise<void> {
return txnAsPromise(this._txn);
async complete(log?: LogItem): Promise<void> {
try {
await txnAsPromise(this._txn);
} catch (err) {
if (this._writeErrors.length) {
this._logWriteErrors(log);
throw this._writeErrors[0].error;
}
throw err;
}
}
abort(): void {
getCause(error: Error) {
if (error instanceof StorageError) {
if (error.errcode === "AbortError" && this._writeErrors.length) {
return this._writeErrors[0].error;
}
}
return error;
}
abort(log?: LogItem): void {
// TODO: should we wrap the exception in a StorageError?
this._txn.abort();
try {
this._txn.abort();
} catch (abortErr) {
log?.set("couldNotAbortTxn", true);
}
if (this._writeErrors.length) {
this._logWriteErrors(log);
}
}
addWriteError(error: StorageError, refItem: LogItem | undefined, operationName: string, key: IDBValidKey | IDBKeyRange | undefined) {
// don't log subsequent `AbortError`s
if (error.errcode !== "AbortError" || this._writeErrors.length === 0) {
this._writeErrors.push(new WriteErrorInfo(error, refItem, operationName, key));
}
}
private _logWriteErrors(parentItem: LogItem | undefined) {
const callback = errorGroupItem => {
// we don't have context when there is no parentItem, so at least log stores
if (!parentItem) {
errorGroupItem.set("allowedStoreNames", this._allowedStoreNames);
}
for (const info of this._writeErrors) {
errorGroupItem.wrap({l: info.operationName, id: info.key}, item => {
if (info.refItem) {
item.refDetached(info.refItem);
}
item.catch(info.error);
});
}
};
const label = `${this._writeErrors.length} storage write operation(s) failed`;
if (parentItem) {
parentItem.wrap(label, callback);
} else {
this.logger.run(label, callback);
}
}
}

8
src/matrix/storage/idb/stores/DeviceIdentityStore.ts
View file

@ -78,14 +78,14 @@ export class DeviceIdentityStore {
return this._store.index("byCurve25519Key").get(curve25519Key);
}
remove(userId: string, deviceId: string): Promise<undefined> {
return this._store.delete(encodeKey(userId, deviceId));
remove(userId: string, deviceId: string): void {
this._store.delete(encodeKey(userId, deviceId));
}
removeAllForUser(userId: string): Promise<undefined> {
removeAllForUser(userId: string): void {
// exclude both keys as they are theoretical min and max,
// but we should't have a match for just the room id, or room id with max
const range = this._store.IDBKeyRange.bound(encodeKey(userId, MIN_UNICODE), encodeKey(userId, MAX_UNICODE), true, true);
return this._store.delete(range);
this._store.delete(range);
}
}

4
src/matrix/storage/idb/stores/GroupSessionDecryptionStore.ts
View file

@ -44,11 +44,11 @@ export class GroupSessionDecryptionStore {
this._store.put(decryption as GroupSessionEntry);
}
removeAllForRoom(roomId: string): Promise<undefined> {
removeAllForRoom(roomId: string): void {
const range = this._store.IDBKeyRange.bound(
encodeKey(roomId, MIN_UNICODE, MIN_UNICODE),
encodeKey(roomId, MAX_UNICODE, MAX_UNICODE)
);
return this._store.delete(range);
this._store.delete(range);
}
}

4
src/matrix/storage/idb/stores/InboundGroupSessionStore.ts
View file

@ -53,11 +53,11 @@ export class InboundGroupSessionStore {
this._store.put(session);
}
removeAllForRoom(roomId: string): Promise<undefined> {
removeAllForRoom(roomId: string) {
const range = this._store.IDBKeyRange.bound(
encodeKey(roomId, MIN_UNICODE, MIN_UNICODE),
encodeKey(roomId, MAX_UNICODE, MAX_UNICODE)
);
return this._store.delete(range);
this._store.delete(range);
}
}

4
src/matrix/storage/idb/stores/OlmSessionStore.ts
View file

@ -71,7 +71,7 @@ export class OlmSessionStore {
this._store.put(session as OlmSessionEntry);
}
remove(senderKey: string, sessionId: string): Promise<undefined> {
return this._store.delete(encodeKey(senderKey, sessionId));
remove(senderKey: string, sessionId: string): void {
this._store.delete(encodeKey(senderKey, sessionId));
}
}

4
src/matrix/storage/idb/stores/OperationStore.ts
View file

@ -73,8 +73,8 @@ export class OperationStore {
this._store.put(operation as OperationEntry);
}
remove(id: string): Promise<undefined> {
return this._store.delete(id);
remove(id: string): void {
this._store.delete(id);
}
async removeAllForScope(scope: string): Promise<undefined> {

4
src/matrix/storage/idb/stores/OutboundGroupSessionStore.ts
View file

@ -28,8 +28,8 @@ export class OutboundGroupSessionStore {
this._store = store;
}
remove(roomId: string): Promise<undefined> {
return this._store.delete(roomId);
remove(roomId: string): void {
this._store.delete(roomId);
}
get(roomId: string): Promise<OutboundSession | null> {

8
src/matrix/storage/idb/stores/PendingEventStore.ts
View file

@ -62,9 +62,9 @@ export class PendingEventStore {
}
}
remove(roomId: string, queueIndex: number): Promise<undefined> {
remove(roomId: string, queueIndex: number) {
const keyRange = this._eventStore.IDBKeyRange.only(encodeKey(roomId, queueIndex));
return this._eventStore.delete(keyRange);
this._eventStore.delete(keyRange);
}
async exists(roomId: string, queueIndex: number): Promise<boolean> {
@ -86,10 +86,10 @@ export class PendingEventStore {
return this._eventStore.selectAll();
}
removeAllForRoom(roomId: string): Promise<undefined> {
removeAllForRoom(roomId: string): void {
const minKey = encodeKey(roomId, KeyLimits.minStorageKey);
const maxKey = encodeKey(roomId, KeyLimits.maxStorageKey);
const range = this._eventStore.IDBKeyRange.bound(minKey, maxKey);
return this._eventStore.delete(range);
this._eventStore.delete(range);
}
}

4
src/matrix/storage/idb/stores/RoomStateStore.ts
View file

@ -47,10 +47,10 @@ export class RoomStateStore {
this._roomStateStore.put(entry);
}
removeAllForRoom(roomId: string): Promise<undefined> {
removeAllForRoom(roomId: string): void {
// exclude both keys as they are theoretical min and max,
// but we should't have a match for just the room id, or room id with max
const range = this._roomStateStore.IDBKeyRange.bound(roomId, `${roomId}|${MAX_UNICODE}`, true, true);
return this._roomStateStore.delete(range);
this._roomStateStore.delete(range);
}
}

4
src/matrix/storage/idb/stores/RoomSummaryStore.ts
View file

@ -55,7 +55,7 @@ export class RoomSummaryStore {
return roomId === fetchedKey;
}
remove(roomId: string): Promise<undefined> {
return this._summaryStore.delete(roomId);
remove(roomId: string): void {
this._summaryStore.delete(roomId);
}
}

6
src/matrix/storage/idb/stores/TimelineEventStore.ts
View file

@ -20,6 +20,7 @@ import { encodeUint32 } from "../utils";
import {KeyLimits} from "../../common";
import {Store} from "../Store";
import {TimelineEvent, StateEvent} from "../../types";
import {LogItem} from "../../../../logging/LogItem.js";
interface Annotation {
count: number;
@ -265,11 +266,10 @@ export class TimelineEventStore {
* @return nothing. To wait for the operation to finish, await the transaction it's part of.
* @throws {StorageError} ...
*/
insert(entry: TimelineEventEntry): void {
insert(entry: TimelineEventEntry, log: LogItem): void {
(entry as TimelineEventStorageEntry).key = encodeKey(entry.roomId, entry.fragmentId, entry.eventIndex);
(entry as TimelineEventStorageEntry).eventIdKey = encodeEventIdKey(entry.roomId, entry.event.event_id);
// TODO: map error? or in idb/store?
this._timelineStore.add(entry as TimelineEventStorageEntry);
this._timelineStore.add(entry as TimelineEventStorageEntry, log);
}
/** Updates the entry into the store with the given [roomId, eventKey] combination.

4
src/matrix/storage/idb/stores/TimelineFragmentStore.ts
View file

@ -87,7 +87,7 @@ export class TimelineFragmentStore {
return this._store.get(encodeKey(roomId, fragmentId));
}
removeAllForRoom(roomId: string): Promise<undefined> {
return this._store.delete(this._allRange(roomId));
removeAllForRoom(roomId: string): void {
this._store.delete(this._allRange(roomId));
}
}

8
src/matrix/storage/idb/stores/TimelineRelationStore.ts
View file

@ -43,18 +43,18 @@ export class TimelineRelationStore {
this._store.add({key: encodeKey(roomId, targetEventId, relType, sourceEventId)});
}
remove(roomId: string, targetEventId: string, relType: string, sourceEventId: string): Promise<undefined> {
return this._store.delete(encodeKey(roomId, targetEventId, relType, sourceEventId));
remove(roomId: string, targetEventId: string, relType: string, sourceEventId: string): void {
this._store.delete(encodeKey(roomId, targetEventId, relType, sourceEventId));
}
removeAllForTarget(roomId: string, targetId: string): Promise<undefined> {
removeAllForTarget(roomId: string, targetId: string): void {
const range = this._store.IDBKeyRange.bound(
encodeKey(roomId, targetId, MIN_UNICODE, MIN_UNICODE),
encodeKey(roomId, targetId, MAX_UNICODE, MAX_UNICODE),
true,
true
);
return this._store.delete(range);
this._store.delete(range);
}
async getForTargetAndType(roomId: string, targetId: string, relType: string): Promise<RelationEntry[]> {

4
src/matrix/storage/idb/stores/UserIdentityStore.ts
View file

@ -36,7 +36,7 @@ export class UserIdentityStore {
this._store.put(userIdentity);
}
remove(userId: string): Promise<undefined> {
return this._store.delete(userId);
remove(userId: string): void {
this._store.delete(userId);
}
}

17
src/matrix/storage/idb/utils.ts
View file

@ -17,6 +17,7 @@ limitations under the License.
import { IDBRequestError } from "./error";
import { StorageError } from "../common";
import { AbortError } from "../../../utils/error.js";
let needsSyncPromise = false;
@ -112,22 +113,8 @@ export function txnAsPromise(txn): Promise<void> {
// @ts-ignore
needsSyncPromise && Promise._flush && Promise._flush();
});
txn.addEventListener("error", event => {
const request = event.target;
// catch first error here, but don't reject yet,
// as we don't have access to the failed request in the abort event handler
if (!error && request) {
error = new IDBRequestError(request);
}
});
txn.addEventListener("abort", event => {
if (!error) {
const txn = event.target;
const dbName = txn.db.name;
const storeNames = Array.from(txn.objectStoreNames).join(", ")
error = new StorageError(`Transaction on ${dbName} with stores ${storeNames} was aborted.`);
}
reject(error);
reject(new AbortError());
// @ts-ignore
needsSyncPromise && Promise._flush && Promise._flush();
});