log both to idb storage and console, include open items in export

refactor logging api so a logger has multiple reporters, IDBLogPersister
and/or ConsoleReporter.

By default, we add the idb persister for production and both for dev
You can also inject your own logger when creating the platform now.
This commit is contained in:
Bruno Windels 2022-05-06 15:54:45 +02:00
parent 1a08616df1
commit 0fdc6b1c3a
9 changed files with 182 additions and 103 deletions

View file

@ -136,7 +136,8 @@ export class SettingsViewModel extends ViewModel {
}
async exportLogs() {
const logExport = await this.logger.export();
const persister = this.logger.reporters.find(r => typeof r.export === "function");
const logExport = await persister.export();
this.platform.saveFileAs(logExport.asBlob(), `hydrogen-logs-${this.platform.clock.now()}.json`);
}

View file

@ -14,6 +14,9 @@ See the License for the specific language governing permissions and
limitations under the License.
*/
export {Logger} from "./logging/Logger";
export {IDBLogPersister} from "./logging/IDBLogPersister";
export {ConsoleReporter} from "./logging/ConsoleReporter";
export {Platform} from "./platform/web/Platform.js";
export {Client, LoadStatus} from "./matrix/Client.js";
export {RoomStatus} from "./matrix/room/common";

View file

@ -13,22 +13,27 @@ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/
import {BaseLogger} from "./BaseLogger";
import {LogItem} from "./LogItem";
import type {ILogItem, LogItemValues, ILogExport} from "./types";
export class ConsoleLogger extends BaseLogger {
_persistItem(item: LogItem): void {
printToConsole(item);
import type {ILogger, ILogItem, LogItemValues, ILogReporter} from "./types";
import type {LogItem} from "./LogItem";
export class ConsoleReporter implements ILogReporter {
private logger?: ILogger;
reportItem(item: ILogItem): void {
printToConsole(item as LogItem);
}
async export(): Promise<ILogExport | undefined> {
return undefined;
setLogger(logger: ILogger) {
this.logger = logger;
}
printOpenItems(): void {
for (const item of this._openItems) {
this._persistItem(item);
if (!this.logger) {
return;
}
for (const item of this.logger.getOpenRootItems()) {
this.reportItem(item);
}
}
}

View file

@ -22,36 +22,69 @@ import {
iterateCursor,
fetchResults,
} from "../matrix/storage/idb/utils";
import {BaseLogger} from "./BaseLogger";
import type {Interval} from "../platform/web/dom/Clock";
import type {Platform} from "../platform/web/Platform.js";
import type {BlobHandle} from "../platform/web/dom/BlobHandle.js";
import type {ILogItem, ILogExport, ISerializedItem} from "./types";
import type {LogFilter} from "./LogFilter";
import type {ILogItem, ILogger, ILogReporter, ISerializedItem} from "./types";
import {LogFilter} from "./LogFilter";
type QueuedItem = {
json: string;
id?: number;
}
export class IDBLogger extends BaseLogger {
private readonly _name: string;
private readonly _limit: number;
type Options = {
name: string,
flushInterval?: number,
limit?: number,
platform: Platform,
serializedTransformer?: (item: ISerializedItem) => ISerializedItem
}
export class IDBLogPersister implements ILogReporter {
private readonly _flushInterval: Interval;
private _queuedItems: QueuedItem[];
private readonly options: Options;
private logger?: ILogger;
constructor(options: {name: string, flushInterval?: number, limit?: number, platform: Platform, serializedTransformer?: (item: ISerializedItem) => ISerializedItem}) {
super(options);
const {name, flushInterval = 60 * 1000, limit = 3000} = options;
this._name = name;
this._limit = limit;
constructor(options: Options) {
this.options = options;
this._queuedItems = this._loadQueuedItems();
// TODO: also listen for unload just in case sync keeps on running after pagehide is fired?
window.addEventListener("pagehide", this, false);
this._flushInterval = this._platform.clock.createInterval(() => this._tryFlush(), flushInterval);
this._flushInterval = this.options.platform.clock.createInterval(
() => this._tryFlush(),
this.options.flushInterval ?? 60 * 1000
);
}
// TODO: move dispose to ILogger, listen to pagehide elsewhere and call dispose from there, which calls _finishAllAndFlush
setLogger(logger: ILogger): void {
this.logger = logger;
}
reportItem(logItem: ILogItem, filter: LogFilter, forced: boolean): void {
const queuedItem = this.prepareItemForQueue(logItem, filter, forced);
if (queuedItem) {
this._queuedItems.push(queuedItem);
}
}
async export(): Promise<IDBLogExport> {
const db = await this._openDB();
try {
const txn = db.transaction(["logs"], "readonly");
const logs = txn.objectStore("logs");
const storedItems: QueuedItem[] = await fetchResults(logs.openCursor(), () => false);
const openItems = this.getSerializedOpenItems();
const allItems = storedItems.concat(this._queuedItems).concat(openItems);
return new IDBLogExport(allItems, this, this.options.platform);
} finally {
try {
db.close();
} catch (e) {}
}
}
dispose(): void {
window.removeEventListener("pagehide", this, false);
this._flushInterval.dispose();
@ -63,7 +96,7 @@ export class IDBLogger extends BaseLogger {
}
}
async _tryFlush(): Promise<void> {
private async _tryFlush(): Promise<void> {
const db = await this._openDB();
try {
const txn = db.transaction(["logs"], "readwrite");
@ -73,9 +106,10 @@ export class IDBLogger extends BaseLogger {
logs.add(i);
}
const itemCount = await reqAsPromise(logs.count());
if (itemCount > this._limit) {
const limit = this.options.limit ?? 3000;
if (itemCount > limit) {
// delete an extra 10% so we don't need to delete every time we flush
let deleteAmount = (itemCount - this._limit) + Math.round(0.1 * this._limit);
let deleteAmount = (itemCount - limit) + Math.round(0.1 * limit);
await iterateCursor(logs.openCursor(), (_, __, cursor) => {
cursor.delete();
deleteAmount -= 1;
@ -93,14 +127,16 @@ export class IDBLogger extends BaseLogger {
}
}
_finishAllAndFlush(): void {
this._finishOpenItems();
this.log({l: "pagehide, closing logs", t: "navigation"});
private _finishAllAndFlush(): void {
if (this.logger) {
this.logger.log({l: "pagehide, closing logs", t: "navigation"});
this.logger.forceFinish();
}
this._persistQueuedItems(this._queuedItems);
}
_loadQueuedItems(): QueuedItem[] {
const key = `${this._name}_queuedItems`;
private _loadQueuedItems(): QueuedItem[] {
const key = `${this.options.name}_queuedItems`;
try {
const json = window.localStorage.getItem(key);
if (json) {
@ -113,44 +149,32 @@ export class IDBLogger extends BaseLogger {
return [];
}
_openDB(): Promise<IDBDatabase> {
return openDatabase(this._name, db => db.createObjectStore("logs", {keyPath: "id", autoIncrement: true}), 1);
private _openDB(): Promise<IDBDatabase> {
return openDatabase(this.options.name, db => db.createObjectStore("logs", {keyPath: "id", autoIncrement: true}), 1);
}
_persistItem(logItem: ILogItem, filter: LogFilter, forced: boolean): void {
const serializedItem = logItem.serialize(filter, undefined, forced);
private prepareItemForQueue(logItem: ILogItem, filter: LogFilter, forced: boolean): QueuedItem | undefined {
let serializedItem = logItem.serialize(filter, undefined, forced);
if (serializedItem) {
const transformedSerializedItem = this._serializedTransformer(serializedItem);
this._queuedItems.push({
json: JSON.stringify(transformedSerializedItem)
});
if (this.options.serializedTransformer) {
serializedItem = this.options.serializedTransformer(serializedItem);
}
return {
json: JSON.stringify(serializedItem)
};
}
}
_persistQueuedItems(items: QueuedItem[]): void {
private _persistQueuedItems(items: QueuedItem[]): void {
try {
window.localStorage.setItem(`${this._name}_queuedItems`, JSON.stringify(items));
window.localStorage.setItem(`${this.options.name}_queuedItems`, JSON.stringify(items));
} catch (e) {
console.error("Could not persist queued log items in localStorage, they will likely be lost", e);
}
}
async export(): Promise<ILogExport> {
const db = await this._openDB();
try {
const txn = db.transaction(["logs"], "readonly");
const logs = txn.objectStore("logs");
const storedItems: QueuedItem[] = await fetchResults(logs.openCursor(), () => false);
const allItems = storedItems.concat(this._queuedItems);
return new IDBLogExport(allItems, this, this._platform);
} finally {
try {
db.close();
} catch (e) {}
}
}
async _removeItems(items: QueuedItem[]): Promise<void> {
/** @internal called by ILogExport.removeFromStore */
async removeItems(items: QueuedItem[]): Promise<void> {
const db = await this._openDB();
try {
const txn = db.transaction(["logs"], "readwrite");
@ -173,14 +197,29 @@ export class IDBLogger extends BaseLogger {
} catch (e) {}
}
}
private getSerializedOpenItems(): QueuedItem[] {
const openItems: QueuedItem[] = [];
if (!this.logger) {
return openItems;
}
const filter = new LogFilter();
for(const item of this.logger!.getOpenRootItems()) {
const openItem = this.prepareItemForQueue(item, filter, false);
if (openItem) {
openItems.push(openItem);
}
}
return openItems;
}
}
class IDBLogExport implements ILogExport {
export class IDBLogExport {
private readonly _items: QueuedItem[];
private readonly _logger: IDBLogger;
private readonly _logger: IDBLogPersister;
private readonly _platform: Platform;
constructor(items: QueuedItem[], logger: IDBLogger, platform: Platform) {
constructor(items: QueuedItem[], logger: IDBLogPersister, platform: Platform) {
this._items = items;
this._logger = logger;
this._platform = platform;
@ -194,18 +233,23 @@ class IDBLogExport implements ILogExport {
* @return {Promise}
*/
removeFromStore(): Promise<void> {
return this._logger._removeItems(this._items);
return this._logger.removeItems(this._items);
}
asBlob(): BlobHandle {
const json = this.asJSON();
const buffer: Uint8Array = this._platform.encoding.utf8.encode(json);
const blob: BlobHandle = this._platform.createBlob(buffer, "application/json");
return blob;
}
asJSON(): string {
const log = {
formatVersion: 1,
appVersion: this._platform.updateService?.version,
items: this._items.map(i => JSON.parse(i.json))
};
const json = JSON.stringify(log);
const buffer: Uint8Array = this._platform.encoding.utf8.encode(json);
const blob: BlobHandle = this._platform.createBlob(buffer, "application/json");
return blob;
return json;
}
}

View file

@ -16,7 +16,7 @@ limitations under the License.
*/
import {LogLevel, LogFilter} from "./LogFilter";
import type {BaseLogger} from "./BaseLogger";
import type {Logger} from "./Logger";
import type {ISerializedItem, ILogItem, LogItemValues, LabelOrValues, FilterCreator, LogCallback} from "./types";
export class LogItem implements ILogItem {
@ -25,11 +25,11 @@ export class LogItem implements ILogItem {
public error?: Error;
public end?: number;
private _values: LogItemValues;
protected _logger: BaseLogger;
protected _logger: Logger;
private _filterCreator?: FilterCreator;
private _children?: Array<LogItem>;
constructor(labelOrValues: LabelOrValues, logLevel: LogLevel, logger: BaseLogger, filterCreator?: FilterCreator) {
constructor(labelOrValues: LabelOrValues, logLevel: LogLevel, logger: Logger, filterCreator?: FilterCreator) {
this._logger = logger;
this.start = logger._now();
// (l)abel
@ -38,7 +38,7 @@ export class LogItem implements ILogItem {
this._filterCreator = filterCreator;
}
/** start a new root log item and run it detached mode, see BaseLogger.runDetached */
/** start a new root log item and run it detached mode, see Logger.runDetached */
runDetached(labelOrValues: LabelOrValues, callback: LogCallback<unknown>, logLevel?: LogLevel, filterCreator?: FilterCreator): ILogItem {
return this._logger.runDetached(labelOrValues, callback, logLevel, filterCreator);
}
@ -253,7 +253,7 @@ export class LogItem implements ILogItem {
return item;
}
get logger(): BaseLogger {
get logger(): Logger {
return this._logger;
}

View file

@ -17,17 +17,17 @@ limitations under the License.
import {LogItem} from "./LogItem";
import {LogLevel, LogFilter} from "./LogFilter";
import type {ILogger, ILogExport, FilterCreator, LabelOrValues, LogCallback, ILogItem, ISerializedItem} from "./types";
import type {ILogger, ILogReporter, FilterCreator, LabelOrValues, LogCallback, ILogItem, ISerializedItem} from "./types";
import type {Platform} from "../platform/web/Platform.js";
export abstract class BaseLogger implements ILogger {
export class Logger implements ILogger {
protected _openItems: Set<LogItem> = new Set();
protected _platform: Platform;
protected _serializedTransformer: (item: ISerializedItem) => ISerializedItem;
public readonly reporters: ILogReporter[] = [];
constructor({platform, serializedTransformer = (item: ISerializedItem) => item}) {
constructor({platform}) {
this._platform = platform;
this._serializedTransformer = serializedTransformer;
}
log(labelOrValues: LabelOrValues, logLevel: LogLevel = LogLevel.Info): void {
@ -79,10 +79,10 @@ export abstract class BaseLogger implements ILogger {
return this._run(item, callback, logLevel, true, filterCreator);
}
_run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: true, filterCreator?: FilterCreator): T;
private _run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: true, filterCreator?: FilterCreator): T;
// we don't return if we don't throw, as we don't have anything to return when an error is caught but swallowed for the fire-and-forget case.
_run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: false, filterCreator?: FilterCreator): void;
_run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: boolean, filterCreator?: FilterCreator): T | void {
private _run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: false, filterCreator?: FilterCreator): void;
private _run<T>(item: LogItem, callback: LogCallback<T>, logLevel: LogLevel, wantResult: boolean, filterCreator?: FilterCreator): T | void {
this._openItems.add(item);
const finishItem = () => {
@ -134,7 +134,16 @@ export abstract class BaseLogger implements ILogger {
}
}
_finishOpenItems() {
addReporter(reporter: ILogReporter): void {
reporter.setLogger(this);
this.reporters.push(reporter);
}
getOpenRootItems(): Iterable<ILogItem> {
return this._openItems;
}
forceFinish() {
for (const openItem of this._openItems) {
openItem.forceFinish();
try {
@ -150,19 +159,24 @@ export abstract class BaseLogger implements ILogger {
this._openItems.clear();
}
abstract _persistItem(item: LogItem, filter?: LogFilter, forced?: boolean): void;
abstract export(): Promise<ILogExport | undefined>;
/** @internal */
_persistItem(item: LogItem, filter?: LogFilter, forced?: boolean): void {
for (var i = 0; i < this.reporters.length; i += 1) {
this.reporters[i].reportItem(item, filter, forced);
}
}
// expose log level without needing
get level(): typeof LogLevel {
return LogLevel;
}
/** @internal */
_now(): number {
return this._platform.clock.now();
}
/** @internal */
_createRefId(): number {
return Math.round(this._platform.random() * Number.MAX_SAFE_INTEGER);
}
@ -171,7 +185,7 @@ export abstract class BaseLogger implements ILogger {
class DeferredPersistRootLogItem extends LogItem {
finish() {
super.finish();
(this._logger as BaseLogger)._persistItem(this, undefined, false);
(this._logger as Logger)._persistItem(this, undefined, false);
}
forceFinish() {

View file

@ -14,7 +14,7 @@ See the License for the specific language governing permissions and
limitations under the License.
*/
import {LogLevel} from "./LogFilter";
import type {ILogger, ILogExport, ILogItem, LabelOrValues, LogCallback, LogItemValues} from "./types";
import type {ILogger, ILogItem, LabelOrValues, LogCallback, LogItemValues} from "./types";
function noop (): void {}
@ -23,6 +23,14 @@ export class NullLogger implements ILogger {
log(): void {}
addReporter() {}
getOpenRootItems(): Iterable<ILogItem> {
return [];
}
forceFinish(): void {}
child(): ILogItem {
return this.item;
}
@ -43,11 +51,7 @@ export class NullLogger implements ILogger {
new Promise(r => r(callback(this.item))).then(noop, noop);
return this.item;
}
async export(): Promise<ILogExport | undefined> {
return undefined;
}
get level(): typeof LogLevel {
return LogLevel;
}

View file

@ -16,7 +16,6 @@ limitations under the License.
*/
import {LogLevel, LogFilter} from "./LogFilter";
import type {BaseLogger} from "./BaseLogger";
import type {BlobHandle} from "../platform/web/dom/BlobHandle.js";
export interface ISerializedItem {
@ -40,7 +39,7 @@ export interface ILogItem {
readonly level: typeof LogLevel;
readonly end?: number;
readonly start?: number;
readonly values: LogItemValues;
readonly values: Readonly<LogItemValues>;
wrap<T>(labelOrValues: LabelOrValues, callback: LogCallback<T>, logLevel?: LogLevel, filterCreator?: FilterCreator): T;
/*** This is sort of low-level, you probably want to use wrap. If you do use it, it should only be called once. */
run<T>(callback: LogCallback<T>): T;
@ -74,14 +73,20 @@ export interface ILogger {
wrapOrRun<T>(item: ILogItem | undefined, labelOrValues: LabelOrValues, callback: LogCallback<T>, logLevel?: LogLevel, filterCreator?: FilterCreator): T;
runDetached<T>(labelOrValues: LabelOrValues, callback: LogCallback<T>, logLevel?: LogLevel, filterCreator?: FilterCreator): ILogItem;
run<T>(labelOrValues: LabelOrValues, callback: LogCallback<T>, logLevel?: LogLevel, filterCreator?: FilterCreator): T;
export(): Promise<ILogExport | undefined>;
get level(): typeof LogLevel;
getOpenRootItems(): Iterable<ILogItem>;
addReporter(reporter: ILogReporter): void;
get reporters(): ReadonlyArray<ILogReporter>;
/**
* force-finishes any open items and passes them to the reporter, with the forced flag set.
* Good think to do when the page is being closed to not lose any logs.
**/
forceFinish(): void;
}
export interface ILogExport {
get count(): number;
removeFromStore(): Promise<void>;
asBlob(): BlobHandle;
export interface ILogReporter {
setLogger(logger: ILogger): void;
reportItem(item: ILogItem, filter?: LogFilter, forced?: boolean): void;
}
export type LogItemValues = {

View file

@ -21,8 +21,9 @@ import {SessionInfoStorage} from "../../matrix/sessioninfo/localstorage/SessionI
import {SettingsStorage} from "./dom/SettingsStorage.js";
import {Encoding} from "./utils/Encoding.js";
import {OlmWorker} from "../../matrix/e2ee/OlmWorker.js";
import {IDBLogger} from "../../logging/IDBLogger";
import {ConsoleLogger} from "../../logging/ConsoleLogger";
import {IDBLogPersister} from "../../logging/IDBLogPersister";
import {ConsoleReporter} from "../../logging/ConsoleReporter";
import {Logger} from "../../logging/Logger";
import {RootView} from "./ui/RootView.js";
import {Clock} from "./dom/Clock.js";
import {ServiceWorkerHandler} from "./dom/ServiceWorkerHandler.js";
@ -128,7 +129,7 @@ function adaptUIOnVisualViewportResize(container) {
}
export class Platform {
constructor({ container, assetPaths, config, configURL, options = null, cryptoExtras = null }) {
constructor({ container, assetPaths, config, configURL, logger, options = null, cryptoExtras = null }) {
this._container = container;
this._assetPaths = assetPaths;
this._config = config;
@ -137,7 +138,7 @@ export class Platform {
this.clock = new Clock();
this.encoding = new Encoding();
this.random = Math.random;
this._createLogger(options?.development);
this.logger = logger ?? this._createLogger(options?.development);
this.history = new History();
this.onlineStatus = new OnlineStatus();
this._serviceWorkerHandler = null;
@ -185,6 +186,7 @@ export class Platform {
}
_createLogger(isDevelopment) {
const logger = new Logger({platform: this});
// Make sure that loginToken does not end up in the logs
const transformer = (item) => {
if (item.e?.stack) {
@ -192,11 +194,12 @@ export class Platform {
}
return item;
};
const logPersister = new IDBLogPersister({name: "hydrogen_logs", platform: this, serializedTransformer: transformer});
logger.addReporter(logPersister);
if (isDevelopment) {
this.logger = new ConsoleLogger({platform: this});
} else {
this.logger = new IDBLogger({name: "hydrogen_logs", platform: this, serializedTransformer: transformer});
logger.addReporter(new ConsoleReporter());
}
return logger;
}
get updateService() {