1
0
mirror of https://github.com/matrix-org/matrix-js-sdk.git synced 2025-11-29 16:43:09 +03:00

Add more debug logs to encryption prep

This continues work from https://github.com/matrix-org/matrix-js-sdk/pull/1580
and adds more logging, including specialised logging for a potential cause of
https://github.com/vector-im/element-web/issues/16194.

So far, it seems clear that something's going wrong in the "sharing keys with
new Olm session" step.
This commit is contained in:
J. Ryan Stinnett
2021-02-17 13:45:26 +00:00
parent 07e6b47fa7
commit 4a0f848551
2 changed files with 23 additions and 6 deletions

View File

@@ -743,16 +743,17 @@ MegolmEncryption.prototype._shareKeyWithOlmSessions = async function(
const userDeviceMaps = this._splitDevices(devicemap); const userDeviceMaps = this._splitDevices(devicemap);
for (let i = 0; i < userDeviceMaps.length; i++) { for (let i = 0; i < userDeviceMaps.length; i++) {
const taskDetail =
`megolm keys for ${session.sessionId} ` +
`in ${this._roomId} (slice ${i + 1}/${userDeviceMaps.length})`;
try { try {
logger.debug(`Sharing ${taskDetail}`);
await this._encryptAndSendKeysToDevices( await this._encryptAndSendKeysToDevices(
session, key.chain_index, userDeviceMaps[i], payload, session, key.chain_index, userDeviceMaps[i], payload,
); );
logger.log(`Completed megolm keyshare for ${session.sessionId} ` logger.debug(`Shared ${taskDetail}`);
+ `in ${this._roomId} (slice ${i + 1}/${userDeviceMaps.length})`);
} catch (e) { } catch (e) {
logger.log(`megolm keyshare for ${session.sessionId} in ${this._roomId} ` logger.error(`Failed to share ${taskDetail}`);
+ `(slice ${i + 1}/${userDeviceMaps.length}) failed`);
throw e; throw e;
} }
} }

View File

@@ -277,16 +277,29 @@ export async function ensureOlmSessionsForDevices(
const oneTimeKeyAlgorithm = "signed_curve25519"; const oneTimeKeyAlgorithm = "signed_curve25519";
let res; let res;
let taskDetail = `one-time keys for ${devicesWithoutSession.length} devices`;
// If your homeserver takes a nap here and never replies, this process
// would hang indefinitely. While that's easily fixed by setting a
// timeout on this request, let's first log whether that's the root
// cause we're seeing in practice.
// See also https://github.com/vector-im/element-web/issues/16194
const otkTimeoutLogger = setTimeout(() => {
logger.error(`Homeserver never replied while claiming ${taskDetail}`);
}, otkTimeout);
try { try {
logger.debug(`Claiming ${taskDetail}`);
res = await baseApis.claimOneTimeKeys( res = await baseApis.claimOneTimeKeys(
devicesWithoutSession, oneTimeKeyAlgorithm, otkTimeout, devicesWithoutSession, oneTimeKeyAlgorithm, otkTimeout,
); );
logger.debug(`Claimed ${taskDetail}`);
} catch (e) { } catch (e) {
for (const resolver of Object.values(resolveSession)) { for (const resolver of Object.values(resolveSession)) {
resolver.resolve(); resolver.resolve();
} }
logger.log("failed to claim one-time keys", e, devicesWithoutSession); logger.log(`Failed to claim ${taskDetail}`, e, devicesWithoutSession);
throw e; throw e;
} finally {
clearTimeout(otkTimeoutLogger);
} }
if (failedServers && "failures" in res) { if (failedServers && "failures" in res) {
@@ -350,7 +363,10 @@ export async function ensureOlmSessionsForDevices(
} }
} }
taskDetail = `Olm sessions for ${promises.length} devices`;
logger.debug(`Starting ${taskDetail}`);
await Promise.all(promises); await Promise.all(promises);
logger.debug(`Started ${taskDetail}`);
return result; return result;
} }