1
0
mirror of https://github.com/matrix-org/matrix-js-sdk.git synced 2025-11-26 17:03:12 +03:00

Allow applications to specify their own logger instance (#3792)

* Support MatrixClient-specific loggers.

Signed-off-by: Patrick Cloke <clokep@patrick.cloke.us>

* Use client-specific logger in client.ts.

Signed-off-by: Patrick Cloke <clokep@patrick.cloke.us>

* Log `fetch` requests to the per-client logger

* Use client-specific logger in rust-crypto
This commit is contained in:
Richard van der Hoff
2023-10-10 10:34:03 +01:00
committed by GitHub
parent 7c2a12085c
commit 42be793a56
7 changed files with 137 additions and 84 deletions

View File

@@ -52,7 +52,7 @@ import { IExportedDevice as IExportedOlmDevice } from "./crypto/OlmDevice";
import { IOlmDevice } from "./crypto/algorithms/megolm";
import { TypedReEmitter } from "./ReEmitter";
import { IRoomEncryption, RoomList } from "./crypto/RoomList";
import { logger } from "./logger";
import { logger, Logger } from "./logger";
import { SERVICE_TYPES } from "./service-types";
import {
Body,
@@ -415,6 +415,12 @@ export interface ICreateClientOpts {
* so that livekit media can be used in the application layert (js-sdk contains no livekit code).
*/
useLivekitForGroupCalls?: boolean;
/**
* A logger to associate with this MatrixClient.
* Defaults to the built-in global logger.
*/
logger?: Logger;
}
export interface IMatrixClientCreateOpts extends ICreateClientOpts {
@@ -1207,6 +1213,8 @@ const SSO_ACTION_PARAM = new UnstableValue("action", "org.matrix.msc3824.action"
export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHandlerMap> {
public static readonly RESTORE_BACKUP_ERROR_BAD_KEY = "RESTORE_BACKUP_ERROR_BAD_KEY";
private readonly logger: Logger;
public reEmitter = new TypedReEmitter<EmittedEvents, ClientEventHandlerMap>(this);
public olmVersion: [number, number, number] | null = null; // populated after initCrypto
public usingExternalCrypto = false;
@@ -1312,6 +1320,10 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
public constructor(opts: IMatrixClientCreateOpts) {
super();
// If a custom logger is provided, use it. Otherwise, default to the global
// one in logger.ts.
this.logger = opts.logger ?? logger;
opts.baseUrl = utils.ensureNoTrailingSlash(opts.baseUrl);
opts.idBaseUrl = utils.ensureNoTrailingSlash(opts.idBaseUrl);
@@ -1337,21 +1349,22 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
extraParams: opts.queryParams,
localTimeoutMs: opts.localTimeoutMs,
useAuthorizationHeader: opts.useAuthorizationHeader,
logger: this.logger,
});
if (opts.deviceToImport) {
if (this.deviceId) {
logger.warn(
this.logger.warn(
"not importing device because device ID is provided to " +
"constructor independently of exported data",
);
} else if (this.credentials.userId) {
logger.warn(
this.logger.warn(
"not importing device because user ID is provided to " +
"constructor independently of exported data",
);
} else if (!opts.deviceToImport.deviceId) {
logger.warn("not importing device because no device ID in exported data");
this.logger.warn("not importing device because no device ID in exported data");
} else {
this.deviceId = opts.deviceToImport.deviceId;
this.credentials.userId = opts.deviceToImport.userId;
@@ -1523,7 +1536,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (this.syncApi) {
// This shouldn't happen since we thought the client was not running
logger.error("Still have sync object whilst not running: stopping old one");
this.logger.error("Still have sync object whilst not running: stopping old one");
this.syncApi.stop();
}
@@ -1537,7 +1550,10 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
Thread.setServerSideListSupport(list);
Thread.setServerSideFwdPaginationSupport(fwdPagination);
} catch (e) {
logger.error("Can't fetch server versions, continuing to initialise sync, this will be retried later", e);
this.logger.error(
"Can't fetch server versions, continuing to initialise sync, this will be retried later",
e,
);
}
this.clientOpts = opts ?? {};
@@ -1553,7 +1569,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
}
if (this.clientOpts.hasOwnProperty("experimentalThreadSupport")) {
logger.warn("`experimentalThreadSupport` has been deprecated, use `threadSupport` instead");
this.logger.warn("`experimentalThreadSupport` has been deprecated, use `threadSupport` instead");
}
// If `threadSupport` is omitted and the deprecated `experimentalThreadSupport` has been passed
@@ -1565,7 +1581,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
this.clientOpts.threadSupport = this.clientOpts.experimentalThreadSupport;
}
this.syncApi.sync().catch((e) => logger.info("Sync startup aborted with an error:", e));
this.syncApi.sync().catch((e) => this.logger.info("Sync startup aborted with an error:", e));
if (this.clientOpts.clientWellKnownPollPeriod !== undefined) {
this.clientWellKnownIntervalID = setInterval(() => {
@@ -1604,7 +1620,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (!this.clientRunning) return; // already stopped
logger.log("stopping MatrixClient");
this.logger.debug("stopping MatrixClient");
this.clientRunning = false;
@@ -1654,7 +1670,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
}
if (!getDeviceResult.device_data || !getDeviceResult.device_id) {
logger.info("no dehydrated device found");
this.logger.info("no dehydrated device found");
return;
}
@@ -1662,16 +1678,16 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
try {
const deviceData = getDeviceResult.device_data;
if (deviceData.algorithm !== DEHYDRATION_ALGORITHM) {
logger.warn("Wrong algorithm for dehydrated device");
this.logger.warn("Wrong algorithm for dehydrated device");
return;
}
logger.log("unpickling dehydrated device");
this.logger.debug("unpickling dehydrated device");
const key = await this.cryptoCallbacks.getDehydrationKey(deviceData, (k) => {
// copy the key so that it doesn't get clobbered
account.unpickle(new Uint8Array(k), deviceData.account);
});
account.unpickle(key, deviceData.account);
logger.log("unpickled device");
this.logger.debug("unpickled device");
const rehydrateResult = await this.http.authedRequest<{ success: boolean }>(
Method.Post,
@@ -1687,7 +1703,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (rehydrateResult.success) {
this.deviceId = getDeviceResult.device_id;
logger.info("using dehydrated device");
this.logger.info("using dehydrated device");
const pickleKey = this.pickleKey || "DEFAULT_KEY";
this.exportedOlmDeviceToImport = {
pickledAccount: account.pickle(pickleKey),
@@ -1698,12 +1714,12 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
return this.deviceId;
} else {
account.free();
logger.info("not using dehydrated device");
this.logger.info("not using dehydrated device");
return;
}
} catch (e) {
account.free();
logger.warn("could not unpickle", e);
this.logger.warn("could not unpickle", e);
}
}
@@ -1723,7 +1739,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
},
);
} catch (e) {
logger.info("could not get dehydrated device", e);
this.logger.info("could not get dehydrated device", e);
return;
}
}
@@ -1745,7 +1761,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
deviceDisplayName?: string,
): Promise<void> {
if (!this.crypto) {
logger.warn("not dehydrating device if crypto is not enabled");
this.logger.warn("not dehydrating device if crypto is not enabled");
return;
}
return this.crypto.dehydrationManager.setKeyAndQueueDehydration(key, keyInfo, deviceDisplayName);
@@ -1766,7 +1782,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
deviceDisplayName?: string,
): Promise<string | undefined> {
if (!this.crypto) {
logger.warn("not dehydrating device if crypto is not enabled");
this.logger.warn("not dehydrating device if crypto is not enabled");
return;
}
await this.crypto.dehydrationManager.setKey(key, keyInfo, deviceDisplayName);
@@ -1775,7 +1791,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
public async exportDevice(): Promise<IExportedDevice | undefined> {
if (!this.crypto) {
logger.warn("not exporting device if crypto is not enabled");
this.logger.warn("not exporting device if crypto is not enabled");
return;
}
return {
@@ -1818,10 +1834,10 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
`${RUST_SDK_STORE_PREFIX}::matrix-sdk-crypto-meta`,
]) {
const prom = new Promise((resolve, reject) => {
logger.info(`Removing IndexedDB instance ${dbname}`);
this.logger.info(`Removing IndexedDB instance ${dbname}`);
const req = indexedDB.deleteDatabase(dbname);
req.onsuccess = (_): void => {
logger.info(`Removed IndexedDB instance ${dbname}`);
this.logger.info(`Removed IndexedDB instance ${dbname}`);
resolve(0);
};
req.onerror = (e): void => {
@@ -1830,11 +1846,11 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
// database that did not allow mutations."
//
// it seems like the only thing we can really do is ignore the error.
logger.warn(`Failed to remove IndexedDB instance ${dbname}:`, e);
this.logger.warn(`Failed to remove IndexedDB instance ${dbname}:`, e);
resolve(0);
};
req.onblocked = (e): void => {
logger.info(`cannot yet remove IndexedDB instance ${dbname}`);
this.logger.info(`cannot yet remove IndexedDB instance ${dbname}`);
};
});
await prom;
@@ -2141,7 +2157,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (this.cachedCapabilities && !fresh) {
if (now < this.cachedCapabilities.expiration) {
logger.log("Returning cached capabilities");
this.logger.debug("Returning cached capabilities");
return Promise.resolve(this.cachedCapabilities.capabilities);
}
}
@@ -2153,7 +2169,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
.authedRequest<Response>(Method.Get, "/capabilities")
.catch((e: Error): Response => {
// We swallow errors because we need a default object anyhow
logger.error(e);
this.logger.error(e);
return {};
})
.then((r = {}) => {
@@ -2168,7 +2184,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
expiration: now + cacheMs,
};
logger.log("Caching capabilities: ", capabilities);
this.logger.debug("Caching capabilities: ", capabilities);
return capabilities;
});
}
@@ -2191,7 +2207,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
}
if (this.cryptoBackend) {
logger.warn("Attempt to re-initialise e2e encryption on MatrixClient");
this.logger.warn("Attempt to re-initialise e2e encryption on MatrixClient");
return;
}
@@ -2200,11 +2216,11 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
throw new Error(`Cannot enable encryption: no cryptoStore provided`);
}
logger.log("Crypto: Starting up crypto store...");
this.logger.debug("Crypto: Starting up crypto store...");
await this.cryptoStore.startup();
// initialise the list of encrypted rooms (whether or not crypto is enabled)
logger.log("Crypto: initialising roomlist...");
this.logger.debug("Crypto: initialising roomlist...");
await this.roomList.init();
const userId = this.getUserId();
@@ -2244,7 +2260,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
CryptoEvent.KeysChanged,
]);
logger.log("Crypto: initialising crypto object...");
this.logger.debug("Crypto: initialising crypto object...");
await crypto.init({
exportedOlmDevice: this.exportedOlmDeviceToImport,
pickleKey: this.pickleKey,
@@ -2260,7 +2276,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
// upload our keys in the background
this.crypto.uploadDeviceKeys().catch((e) => {
// TODO: throwing away this error is a really bad idea.
logger.error("Error uploading device keys", e);
this.logger.error("Error uploading device keys", e);
});
}
@@ -2281,7 +2297,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
*/
public async initRustCrypto({ useIndexedDB = true }: { useIndexedDB?: boolean } = {}): Promise<void> {
if (this.cryptoBackend) {
logger.warn("Attempt to re-initialise e2e encryption on MatrixClient");
this.logger.warn("Attempt to re-initialise e2e encryption on MatrixClient");
return;
}
@@ -2304,6 +2320,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
// needed.
const RustCrypto = await import("./rust-crypto");
const rustCrypto = await RustCrypto.initRustCrypto(
this.logger,
this.http,
userId,
deviceId,
@@ -2382,7 +2399,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
* @deprecated Does nothing.
*/
public async uploadKeys(): Promise<void> {
logger.warn("MatrixClient.uploadKeys is deprecated");
this.logger.warn("MatrixClient.uploadKeys is deprecated");
}
/**
@@ -3462,7 +3479,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (opts.secureSecretStorage) {
await this.secretStorage.store("m.megolm_backup.v1", encodeBase64(privateKey));
logger.info("Key backup private key stored in secret storage");
this.logger.info("Key backup private key stored in secret storage");
}
return {
@@ -3531,7 +3548,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
// sessions.
await this.checkKeyBackup();
if (!this.getKeyBackupEnabled()) {
logger.error("Key backup not usable even though we just created it");
this.logger.error("Key backup not usable even though we just created it");
}
return res;
@@ -3887,7 +3904,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
this.cryptoBackend
.storeSessionBackupPrivateKey(privKey, backupInfo.version)
.catch((e) => {
logger.warn("Error caching session backup key:", e);
this.logger.warn("Error caching session backup key:", e);
})
.then(cacheCompleteCallback);
@@ -3934,7 +3951,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
key.session_id = targetSessionId!;
keys.push(key);
} catch (e) {
logger.log("Failed to decrypt megolm session from backup", e);
this.logger.debug("Failed to decrypt megolm session from backup", e);
}
}
} finally {
@@ -3980,7 +3997,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
const roomEncryption = this.roomList.getRoomEncryption(roomId);
if (!roomEncryption) {
// unknown room, or unencrypted room
logger.error("Unknown room. Not sharing decryption keys");
this.logger.error("Unknown room. Not sharing decryption keys");
return;
}
@@ -3995,7 +4012,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
if (alg.sendSharedHistoryInboundSessions) {
await alg.sendSharedHistoryInboundSessions(devicesByUser);
} else {
logger.warn("Algorithm does not support sharing previous keys", roomEncryption.algorithm);
this.logger.warn("Algorithm does not support sharing previous keys", roomEncryption.algorithm);
}
}
@@ -4578,7 +4595,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
}
const type = localEvent.getType();
logger.log(`sendEvent of type ${type} in ${roomId} with txnId ${txnId}`);
this.logger.debug(`sendEvent of type ${type} in ${roomId} with txnId ${txnId}`);
localEvent.setTxnId(txnId);
localEvent.setStatus(EventStatus.SENDING);
@@ -4650,7 +4667,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
return promise;
})
.catch((err) => {
logger.error("Error sending event", err.stack || err);
this.logger.error("Error sending event", err.stack || err);
try {
// set the error on the event before we update the status:
// updating the status emits the event, so the state should be
@@ -4658,7 +4675,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
event.error = err;
this.updatePendingEventStatus(room, event, EventStatus.NOT_SENT);
} catch (e) {
logger.error("Exception in error handler!", (<Error>e).stack || err);
this.logger.error("Exception in error handler!", (<Error>e).stack || err);
}
if (err instanceof MatrixError) {
err.event = event;
@@ -4771,7 +4788,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
return this.http
.authedRequest<ISendEventResponse>(Method.Put, path, undefined, event.getWireContent())
.then((res) => {
logger.log(`Event sent to ${event.getRoomId()} with event id ${res.event_id}`);
this.logger.debug(`Event sent to ${event.getRoomId()} with event id ${res.event_id}`);
return res;
});
}
@@ -5871,7 +5888,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
const mapper = this.getEventMapper();
const event = mapper(res.event);
if (event.isRelation(THREAD_RELATION_TYPE.name)) {
logger.warn("Tried loading a regular timeline at the position of a thread event");
this.logger.warn("Tried loading a regular timeline at the position of a thread event");
return undefined;
}
const events = [
@@ -7008,7 +7025,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
// cleanup locks
this.syncLeftRoomsPromise
.then(() => {
logger.log("Marking success of sync left room request");
this.logger.debug("Marking success of sync left room request");
this.syncedLeftRooms = true; // flip the bit on success
})
.finally(() => {
@@ -7213,14 +7230,14 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
let credentialsGood = false;
const remainingTime = this.turnServersExpiry - Date.now();
if (remainingTime > TURN_CHECK_INTERVAL) {
logger.debug("TURN creds are valid for another " + remainingTime + " ms: not fetching new ones.");
this.logger.debug("TURN creds are valid for another " + remainingTime + " ms: not fetching new ones.");
credentialsGood = true;
} else {
logger.debug("Fetching new TURN credentials");
this.logger.debug("Fetching new TURN credentials");
try {
const res = await this.turnServer();
if (res.uris) {
logger.log("Got TURN URIs: " + res.uris + " refresh in " + res.ttl + " secs");
this.logger.debug("Got TURN URIs: " + res.uris + " refresh in " + res.ttl + " secs");
// map the response to a format that can be fed to RTCPeerConnection
const servers: ITurnServer = {
urls: res.uris,
@@ -7234,10 +7251,10 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
this.emit(ClientEvent.TurnServers, this.turnServers);
}
} catch (err) {
logger.error("Failed to get TURN URIs", err);
this.logger.error("Failed to get TURN URIs", err);
if ((<HTTPError>err).httpStatus === 403) {
// We got a 403, so there's no point in looping forever.
logger.info("TURN access unavailable for this account: stopping credentials checks");
this.logger.info("TURN access unavailable for this account: stopping credentials checks");
if (this.checkTurnServersIntervalID !== null) global.clearInterval(this.checkTurnServersIntervalID);
this.checkTurnServersIntervalID = undefined;
this.emit(ClientEvent.TurnServersError, <HTTPError>err, true); // fatal
@@ -7976,7 +7993,10 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
try {
while ((await this.crypto.backupManager.backupPendingKeys(200)) > 0);
} catch (err) {
logger.error("Key backup request failed when logging out. Some keys may be missing from backup", err);
this.logger.error(
"Key backup request failed when logging out. Some keys may be missing from backup",
err,
);
}
}
@@ -8137,7 +8157,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
templatedUrl += "/$eventType";
}
} else if (eventType !== null) {
logger.warn(`eventType: ${eventType} ignored when fetching
this.logger.warn(`eventType: ${eventType} ignored when fetching
relations as relationType is null`);
eventType = null;
}
@@ -9429,7 +9449,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
targets.set(userId, Array.from(deviceMessages.keys()));
}
logger.log(`PUT ${path}`, targets);
this.logger.debug(`PUT ${path}`, targets);
return this.http.authedRequest(Method.Put, path, undefined, body);
}
@@ -9688,7 +9708,7 @@ export class MatrixClient extends TypedEventEmitter<EmittedEvents, ClientEventHa
* @deprecated use supportsThreads() instead
*/
public supportsExperimentalThreads(): boolean {
logger.warn(`supportsExperimentalThreads() is deprecated, use supportThreads() instead`);
this.logger.warn(`supportsExperimentalThreads() is deprecated, use supportThreads() instead`);
return this.clientOpts?.experimentalThreadSupport || false;
}