Skip to content

Commit e257c2e

Browse files
authored
fix(logger): harden storage transport persistence (#32)
* fix(logger): harden storage transport persistence * fix(logger): preserve failed storage batches * fix(logger): preserve queued storage batches Track batches as soon as they are queued so unload temp persistence captures writes waiting behind an in-flight save. Also keep download log export failures explicit by requiring the pre-export flush to succeed. * fix(logger): retry retained storage batches Retry batches kept in _savingLogs during explicit save and download flows so preserved failures are flushed before pruning or exporting logs. * fix(logger): remove time key collisions * test(logger): add browser verification harness
1 parent 81d8927 commit e257c2e

6 files changed

Lines changed: 1254 additions & 56 deletions

File tree

package.json

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
"lint": "yarn prettier -c packages/*/src/**/*",
2929
"start": "cd examples/basic && yarn start",
3030
"test": "lerna run test",
31+
"verify:logger:browser": "node ./scripts/verify-logger-storage-browser.mjs",
3132
"watch": "lerna run watch",
3233
"pre:publish": "lerna run pre:publish",
3334
"update:version": "lerna version --amend --no-git-tag-version",

packages/logger/src/transports/storage.ts

Lines changed: 190 additions & 56 deletions
Original file line numberDiff line numberDiff line change
@@ -18,8 +18,23 @@ const DEFAULT_MAX_LOGS_SIZE = 1024 * 1024 * 100; // 100MB
1818
const DEFAULT_BATCH_TIMEOUT = 1000 * 60 * 5; // 5 minutes
1919
const DEFAULT_EXPIRED_TIME = 1000 * 60 * 60 * 24; // 1 day
2020
const DEFAULT_RECENT_TIME = 1000 * 60 * 60; // 1 hour
21+
const LEGACY_LOG_TABLE = 'logs';
22+
const LOG_TABLE = 'logs_v2';
23+
const CURRENT_DB_VERSION = 2;
24+
25+
export const STORAGE_TRANSPORT_ERROR_EVENT = 'rc-mfe-storage-error';
26+
27+
export type StorageTransportBackgroundError = {
28+
error: unknown;
29+
phase: 'init' | 'persist' | 'prune' | 'restore' | 'restore-parse';
30+
transportName: string;
31+
session?: string;
32+
instanceId: string;
33+
tempStorageKey?: string;
34+
};
2135

2236
interface Logs {
37+
id?: number;
2338
/**
2439
* time of the first log in batched logs
2540
*/
@@ -75,6 +90,10 @@ interface StorageTransportOptions {
7590
* recent time for getting logs, default 1 hour
7691
*/
7792
recentTime?: number;
93+
/**
94+
* receive non-throwing background transport errors
95+
*/
96+
onBackgroundError?: (event: StorageTransportBackgroundError) => void;
7897
}
7998

8099
export type ExtraLogs = {
@@ -97,45 +116,44 @@ export class StorageTransport implements ITransport {
97116

98117
protected _session?: string;
99118

119+
protected _instanceId = `${Date.now()}-${Math.random()
120+
.toString(36)
121+
.slice(2, 10)}`;
122+
100123
constructor(protected _options: StorageTransportOptions = {}) {}
101124

102125
async init({ session }: TransportInitOptions) {
103126
this._session = session;
104127
this._data.session = session;
105128
// TODO: refactor this with teardown
106129
if (this._options.enabled) {
107-
this._initDB().catch((err) => {
108-
console.error('StorageTransport.initDB:', err);
109-
});
130+
this._runInBackground(this._initDB(), 'init');
110131
this._onUnload();
111132
if (global.localStorage) {
112-
const key = `${this._tempKey}-prune-time`;
133+
const key = this._pruneKey;
113134
const PrunedTime = global.localStorage.getItem(key);
114135
if (PrunedTime !== new Date().toLocaleDateString()) {
115136
setTimeout(() => {
116-
this._pruneLogs();
117-
global.localStorage.setItem(key, new Date().toLocaleDateString());
137+
this._runInBackground(
138+
this._pruneLogs().then(() => {
139+
global.localStorage.setItem(key, new Date().toLocaleDateString());
140+
}),
141+
'prune'
142+
);
118143
// Avoid running during peak startup load.
119144
// 5 seconds later
120145
}, 5 * 1000);
121146
}
122147
}
123148
setInterval(() => {
124-
this._pruneLogs();
149+
this._runInBackground(this._pruneLogs(), 'prune');
125150
}, this.expiredTime);
126151
}
127152
}
128153

129154
protected _onUnload() {
130155
if (global.localStorage) {
131-
const tempLogs = global.localStorage.getItem(this._tempKey);
132-
if (tempLogs) {
133-
global.localStorage.removeItem(this._tempKey);
134-
const logs = JSON.parse(tempLogs) as Logs[];
135-
logs.forEach((data) => {
136-
this._saveLogs(data);
137-
});
138-
}
156+
this._restoreTempLogs();
139157
window.addEventListener('beforeunload', () => {
140158
this._saveTemp();
141159
});
@@ -156,13 +174,65 @@ export class StorageTransport implements ITransport {
156174
}
157175
if (saveData.length) {
158176
global.localStorage.setItem(this._tempKey, stringify(saveData));
177+
} else {
178+
global.localStorage.removeItem(this._tempKey);
159179
}
160180
}
161181

162-
protected get _tempKey() {
182+
protected get _tempKeyPrefix() {
163183
return `${this.name}-temp`;
164184
}
165185

186+
protected get _tempKey() {
187+
return `${this._tempKeyPrefix}:${this._instanceId}`;
188+
}
189+
190+
protected get _pruneKey() {
191+
return `${this.name}-prune-time`;
192+
}
193+
194+
protected _getTempKeys() {
195+
if (!global.localStorage) return [];
196+
const keys: string[] = [];
197+
for (let index = 0; index < global.localStorage.length; index += 1) {
198+
const key = global.localStorage.key(index);
199+
if (
200+
key === this._tempKeyPrefix ||
201+
key?.startsWith(`${this._tempKeyPrefix}:`)
202+
) {
203+
keys.push(key);
204+
}
205+
}
206+
return keys;
207+
}
208+
209+
protected _restoreTempLogs() {
210+
this._getTempKeys().forEach((key) => {
211+
const tempLogs = global.localStorage.getItem(key);
212+
if (!tempLogs) return;
213+
try {
214+
const logs = JSON.parse(tempLogs) as Logs[];
215+
this._runInBackground(this._restoreTempKey(key, logs), 'restore', key);
216+
} catch (error) {
217+
this._reportBackgroundError(error, 'restore-parse', key);
218+
}
219+
});
220+
}
221+
222+
protected async _restoreTempKey(key: string, logs: Logs[]) {
223+
const pendingLogs = [...logs];
224+
while (pendingLogs.length) {
225+
const data = pendingLogs[0];
226+
await this._saveLogs(data, true);
227+
pendingLogs.shift();
228+
if (pendingLogs.length) {
229+
global.localStorage.setItem(key, stringify(pendingLogs));
230+
} else {
231+
global.localStorage.removeItem(key);
232+
}
233+
}
234+
}
235+
166236
get options() {
167237
return this._options;
168238
}
@@ -173,13 +243,32 @@ export class StorageTransport implements ITransport {
173243

174244
protected async _initDB() {
175245
const db = new Dexie(this.name);
176-
db.version(this._options.version ?? 1).stores({
177-
logs: '&time, size',
178-
});
179-
this._table = db.table('logs');
180-
db.open().catch((err) => {
181-
console.error(`StorageTransport.initDB:`, err);
246+
db.version(1).stores({
247+
[LEGACY_LOG_TABLE]: '&time, size',
182248
});
249+
db.version(
250+
Math.max(this._options.version ?? CURRENT_DB_VERSION, CURRENT_DB_VERSION)
251+
)
252+
.stores({
253+
[LEGACY_LOG_TABLE]: '&time, size',
254+
[LOG_TABLE]: '++id, time, size',
255+
})
256+
.upgrade(async (tx) => {
257+
const legacyLogs = (await tx.table(LEGACY_LOG_TABLE).toArray()) as Logs[];
258+
if (!legacyLogs.length) return;
259+
const migratedLogs = legacyLogs.map(
260+
({ time, size, messages, session }) => ({
261+
time,
262+
size,
263+
messages,
264+
session,
265+
})
266+
);
267+
await tx.table(LOG_TABLE).bulkPut(migratedLogs);
268+
await tx.table(LEGACY_LOG_TABLE).clear();
269+
});
270+
this._table = db.table(LOG_TABLE);
271+
await db.open();
183272
}
184273

185274
protected _data: Logs = {
@@ -196,18 +285,18 @@ export class StorageTransport implements ITransport {
196285
return this._options.batchTimeout ?? DEFAULT_BATCH_TIMEOUT;
197286
}
198287

199-
protected _timeout: NodeJS.Timeout | null = null;
288+
protected _timeout: ReturnType<typeof setTimeout> | null = null;
200289

201290
write({ payload }: SerializedMessage) {
202291
if (this._options.enabled) {
203292
const message = this._stringify(payload);
204293
this._data.size += message.length;
205294
this._data.messages.push(message);
206295
if (this._data.size > this.batchSize) {
207-
this._saveDB();
296+
this._runInBackground(this._saveDB());
208297
} else if (!this._timeout) {
209298
this._timeout = setTimeout(() => {
210-
this._saveDB();
299+
this._runInBackground(this._saveDB());
211300
}, this.batchTimeout);
212301
}
213302
}
@@ -228,11 +317,12 @@ export class StorageTransport implements ITransport {
228317
* save memory logs to database and prune logs
229318
*/
230319
async saveDB() {
231-
await this._saveDB();
320+
await this._saveDB(true);
321+
await this._flushSavingLogs(true);
232322
await this._pruneLogs();
233323
}
234324

235-
protected _saveDB() {
325+
protected _saveDB(throwOnError = false) {
236326
clearTimeout(this._timeout!);
237327
this._timeout = null;
238328
const data = this._data;
@@ -243,48 +333,91 @@ export class StorageTransport implements ITransport {
243333
session: this._session!,
244334
};
245335
if (!data.messages.length) return;
246-
return this._saveLogs(data);
336+
return this._saveLogs(data, throwOnError);
247337
}
248338

249339
/**
250340
* saving logs promise
251341
*/
252-
savingLogsPromise?: Promise<void>;
342+
savingLogsPromise: Promise<void> = Promise.resolve();
253343

254344
protected _savingLogs = new Set<Logs>();
255345

256-
protected async _checkTimeKey(time: number): Promise<number> {
257-
const count = await this._table?.where('time').equals(time).count();
258-
if (count) {
259-
return this._checkTimeKey(time + 1);
346+
protected _saveLogs(data: Logs, throwOnError = false) {
347+
this._savingLogs.add(data);
348+
const saveOperation = this.savingLogsPromise.then(async () => {
349+
await this._table?.add(data);
350+
this._savingLogs.delete(data);
351+
});
352+
this.savingLogsPromise = saveOperation.catch(() => undefined);
353+
if (throwOnError) {
354+
return saveOperation;
260355
}
261-
return time;
356+
return saveOperation.catch((error) => {
357+
this._reportBackgroundError(error, 'persist');
358+
});
262359
}
263360

264-
protected async _saveLogs(data: Logs) {
265-
this._savingLogs.add(data);
266-
data.time = await this._checkTimeKey(data.time);
267-
const savingLogsPromise = this._table?.add(data).then(() => {
268-
this._savingLogs.delete(data);
269-
if (this.savingLogsPromise === savingLogsPromise) {
270-
this.savingLogsPromise = undefined;
361+
protected _flushSavingLogs(throwOnError = false) {
362+
const flushOperation = this.savingLogsPromise.then(async () => {
363+
const pendingLogs = Array.from(this._savingLogs);
364+
for (const data of pendingLogs) {
365+
await this._saveLogs(data, true);
271366
}
272367
});
273-
if (this.savingLogsPromise) {
274-
const _saveLogsPromise = this.savingLogsPromise;
275-
const nextSaveLogsPromise = Promise.all([
276-
savingLogsPromise,
277-
_saveLogsPromise,
278-
]).then(() => {
279-
if (this.savingLogsPromise === nextSaveLogsPromise) {
280-
this.savingLogsPromise = undefined;
281-
}
282-
});
283-
this.savingLogsPromise = nextSaveLogsPromise;
284-
return nextSaveLogsPromise;
368+
if (throwOnError) {
369+
return flushOperation;
370+
}
371+
return flushOperation.catch((error) => {
372+
this._reportBackgroundError(error, 'persist');
373+
});
374+
}
375+
376+
protected _runInBackground(
377+
task?: Promise<unknown>,
378+
phase: StorageTransportBackgroundError['phase'] = 'persist',
379+
tempStorageKey?: string
380+
) {
381+
void task?.catch((error) => {
382+
this._reportBackgroundError(error, phase, tempStorageKey);
383+
});
384+
}
385+
386+
// Background storage tasks must never surface as application-level rejections,
387+
// but they must remain observable for diagnostics.
388+
protected _reportBackgroundError(
389+
error: unknown,
390+
phase: StorageTransportBackgroundError['phase'] = 'persist',
391+
tempStorageKey?: string
392+
) {
393+
const event = {
394+
error,
395+
phase,
396+
transportName: this.name,
397+
session: this._session,
398+
instanceId: this._instanceId,
399+
tempStorageKey,
400+
};
401+
try {
402+
this._options.onBackgroundError?.(event);
403+
} catch {
404+
//
405+
}
406+
try {
407+
if (
408+
typeof global.dispatchEvent === 'function' &&
409+
typeof CustomEvent === 'function'
410+
) {
411+
global.dispatchEvent(
412+
new CustomEvent(STORAGE_TRANSPORT_ERROR_EVENT, {
413+
detail: event,
414+
})
415+
);
416+
}
417+
} catch {
418+
//
285419
}
286-
this.savingLogsPromise = savingLogsPromise;
287-
return savingLogsPromise;
420+
return event;
288421
}
289422

290423
get expiredTime() {
@@ -480,7 +613,8 @@ export class StorageTransport implements ITransport {
480613
} = {}) {
481614
try {
482615
// save current logs in memory
483-
await this._saveDB();
616+
await this._saveDB(true);
617+
await this._flushSavingLogs(true);
484618
const data = await this.getLogs({ name, recentTime, extraLogs });
485619
if (data) {
486620
await saveAs(data.content, `${data.name}.zip`);

0 commit comments

Comments
 (0)