Cleanup work on DecryptionFailureTracker (#12546)

* Inline `DecryptionFailureTracker.addDecryptionFailure`

* Remove redundant TRACK_INTERVAL

There really doesn't seem to be much point to this batching up of decryption
failure reports. We still call the analytics callback the same number of times.

* Rename `trackedEvents` to `reportedEvents`

* Fix incorrect documentation on `visibleEvents`

This *does* overlap with `failures`.

* Combine `addFailure` and `reportFailure`

* Calculate client properties before starting reporting
This commit is contained in:
Richard van der Hoff 2024-05-17 17:19:31 +01:00 committed by GitHub
parent 75562b1d1b
commit 3e103941d6
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
3 changed files with 51 additions and 113 deletions

View file

@ -93,33 +93,24 @@ export class DecryptionFailureTracker {
* Every `CHECK_INTERVAL_MS`, this map is checked for failures that happened >
* `MAXIMUM_LATE_DECRYPTION_PERIOD` ago (considered undecryptable), or
* decryptions that took > `GRACE_PERIOD_MS` (considered late decryptions).
* These are accumulated in `failuresToReport`.
*
* Any such events are then reported via the `TrackingFn`.
*/
public failures: Map<string, DecryptionFailure> = new Map();
/** Set of event IDs that have been visible to the user.
*
* This will only contain events that are not already in `failures` or in
* `trackedEvents`.
* This will only contain events that are not already in `reportedEvents`.
*/
public visibleEvents: Set<string> = new Set();
/** The failures that will be reported at the next tracking interval. These are
* events that we have decided are undecryptable due to exceeding the
* `MAXIMUM_LATE_DECRYPTION_PERIOD`, or that we decrypted but we consider as late
* decryptions. */
public failuresToReport: Set<DecryptionFailure> = new Set();
/** Event IDs of failures that were tracked previously */
public trackedEvents: Set<string> = new Set();
/** Event IDs of failures that were reported previously */
private reportedEvents: Set<string> = new Set();
/** Set to an interval ID when `start` is called */
public checkInterval: number | null = null;
public trackInterval: number | null = null;
/** Spread the load on `Analytics` by tracking at a low frequency, `TRACK_INTERVAL_MS`. */
public static TRACK_INTERVAL_MS = 60000;
/** Call `checkFailures` every `CHECK_INTERVAL_MS`. */
public static CHECK_INTERVAL_MS = 40000;
@ -181,12 +172,12 @@ export class DecryptionFailureTracker {
return DecryptionFailureTracker.internalInstance;
}
// loadTrackedEvents() {
// this.trackedEvents = new Set(JSON.parse(localStorage.getItem('mx-decryption-failure-event-ids')) || []);
// loadReportedEvents() {
// this.reportedEvents = new Set(JSON.parse(localStorage.getItem('mx-decryption-failure-event-ids')) || []);
// }
// saveTrackedEvents() {
// localStorage.setItem('mx-decryption-failure-event-ids', JSON.stringify([...this.trackedEvents]));
// saveReportedEvents() {
// localStorage.setItem('mx-decryption-failure-event-ids', JSON.stringify([...this.reportedEvents]));
// }
/** Callback for when an event is decrypted.
@ -195,7 +186,7 @@ export class DecryptionFailureTracker {
* handler after a decryption attempt on an event, whether the decryption
* is successful or not.
*
* @param matrixEvent the event that was decrypted
* @param e the event that was decrypted
*
* @param nowTs the current timestamp
*/
@ -213,6 +204,11 @@ export class DecryptionFailureTracker {
const eventId = e.getId()!;
// if it's already reported, we don't need to do anything
if (this.reportedEvents.has(eventId)) {
return;
}
// if we already have a record of this event, use the previously-recorded timestamp
const failure = this.failures.get(eventId);
const ts = failure ? failure.ts : nowTs;
@ -223,8 +219,10 @@ export class DecryptionFailureTracker {
if (this.userDomain !== undefined && senderDomain !== undefined) {
isFederated = this.userDomain !== senderDomain;
}
const wasVisibleToUser = this.visibleEvents.has(eventId);
this.addDecryptionFailure(
this.failures.set(
eventId,
new DecryptionFailure(eventId, errCode, ts, isFederated, wasVisibleToUser, this.userTrustsOwnIdentity),
);
}
@ -233,7 +231,7 @@ export class DecryptionFailureTracker {
const eventId = e.getId()!;
// if it's already reported, we don't need to do anything
if (this.trackedEvents.has(eventId)) {
if (this.reportedEvents.has(eventId)) {
return;
}
@ -247,16 +245,6 @@ export class DecryptionFailureTracker {
this.visibleEvents.add(eventId);
}
public addDecryptionFailure(failure: DecryptionFailure): void {
const eventId = failure.failedEventId;
if (this.trackedEvents.has(eventId)) {
return;
}
this.failures.set(eventId, failure);
}
public removeDecryptionFailuresForEvent(e: MatrixEvent, nowTs: number): void {
const eventId = e.getId()!;
const failure = this.failures.get(eventId);
@ -274,7 +262,7 @@ export class DecryptionFailureTracker {
// undecryptable, and leave timeToDecryptMillis undefined
failure.timeToDecryptMillis = timeToDecryptMillis;
}
this.failuresToReport.add(failure);
this.reportFailure(failure);
}
}
@ -301,15 +289,13 @@ export class DecryptionFailureTracker {
/**
* Start checking for and tracking failures.
*/
public start(client: MatrixClient): void {
this.calculateClientProperties(client);
public async start(client: MatrixClient): Promise<void> {
await this.calculateClientProperties(client);
this.registerHandlers(client);
this.checkInterval = window.setInterval(
() => this.checkFailures(Date.now()),
DecryptionFailureTracker.CHECK_INTERVAL_MS,
);
this.trackInterval = window.setInterval(() => this.trackFailures(), DecryptionFailureTracker.TRACK_INTERVAL_MS);
}
private async calculateClientProperties(client: MatrixClient): Promise<void> {
@ -370,7 +356,6 @@ export class DecryptionFailureTracker {
this.userTrustsOwnIdentity = undefined;
this.failures = new Map();
this.visibleEvents = new Set();
this.failuresToReport = new Set();
}
/**
@ -392,7 +377,7 @@ export class DecryptionFailureTracker {
// - we haven't decrypted yet and it's past the time for it to be
// considered a "late" decryption, so we count it as
// undecryptable.
this.addFailure(eventId, failure);
this.reportFailure(failure);
} else {
// the event isn't old enough, so we still need to keep track of it
failuresNotReady.set(eventId, failure);
@ -402,40 +387,34 @@ export class DecryptionFailureTracker {
// Commented out for now for expediency, we need to consider unbound nature of storing
// this in localStorage
// this.saveTrackedEvents();
}
private addFailure(eventId: string, failure: DecryptionFailure): void {
this.failuresToReport.add(failure);
this.trackedEvents.add(eventId);
// once we've added it to trackedEvents, we won't check
// visibleEvents for it any more
this.visibleEvents.delete(eventId);
// this.saveReportedEvents();
}
/**
* If there are failures that should be tracked, call the given trackDecryptionFailure
* function with the failures that should be tracked.
*/
public trackFailures(): void {
for (const failure of this.failuresToReport) {
const errorCode = failure.errorCode;
const trackedErrorCode = this.errorCodeMapFn(errorCode);
const properties: ErrorProperties = {
timeToDecryptMillis: failure.timeToDecryptMillis ?? -1,
wasVisibleToUser: failure.wasVisibleToUser,
};
if (failure.isFederated !== undefined) {
properties.isFederated = failure.isFederated;
}
if (failure.userTrustsOwnIdentity !== undefined) {
properties.userTrustsOwnIdentity = failure.userTrustsOwnIdentity;
}
if (this.baseProperties) {
Object.assign(properties, this.baseProperties);
}
this.fn(trackedErrorCode, errorCode, properties);
private reportFailure(failure: DecryptionFailure): void {
const errorCode = failure.errorCode;
const trackedErrorCode = this.errorCodeMapFn(errorCode);
const properties: ErrorProperties = {
timeToDecryptMillis: failure.timeToDecryptMillis ?? -1,
wasVisibleToUser: failure.wasVisibleToUser,
};
if (failure.isFederated !== undefined) {
properties.isFederated = failure.isFederated;
}
this.failuresToReport = new Set();
if (failure.userTrustsOwnIdentity !== undefined) {
properties.userTrustsOwnIdentity = failure.userTrustsOwnIdentity;
}
if (this.baseProperties) {
Object.assign(properties, this.baseProperties);
}
this.fn(trackedErrorCode, errorCode, properties);
this.reportedEvents.add(failure.failedEventId);
// once we've added it to reportedEvents, we won't check
// visibleEvents for it any more
this.visibleEvents.delete(failure.failedEventId);
}
}

View file

@ -1591,7 +1591,7 @@ export default class MatrixChat extends React.PureComponent<IProps, IState> {
// tracked events across sessions.
// dft.loadTrackedEventHashMap();
dft.start(cli);
dft.start(cli).catch((e) => logger.error("Unable to start DecryptionFailureTracker", e));
cli.on(ClientEvent.Room, (room) => {
if (cli.isCryptoEnabled()) {

View file

@ -55,9 +55,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Immediately track the newest failures
tracker.trackFailures();
// should track a failure for an event that failed decryption
expect(count).not.toBe(0);
});
@ -84,9 +81,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Immediately track the newest failures
tracker.trackFailures();
// should track a failure for an event that failed decryption
expect(count).not.toBe(0);
@ -110,9 +104,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Immediately track the newest failures
tracker.trackFailures();
// should track a failure for an event that failed decryption
expect(count).not.toBe(0);
});
@ -151,8 +142,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(propertiesByErrorCode[error1].wasVisibleToUser).toBe(true);
expect(propertiesByErrorCode[error2].wasVisibleToUser).toBe(true);
expect(propertiesByErrorCode[error3].wasVisibleToUser).toBe(false);
@ -181,9 +170,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Immediately track the newest failures
tracker.trackFailures();
});
it(
@ -213,9 +199,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Immediately track the newest failures
tracker.trackFailures();
},
);
@ -247,11 +230,9 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
// Simulated polling of `trackFailures`, an arbitrary number ( > 2 ) times
tracker.trackFailures();
tracker.trackFailures();
tracker.trackFailures();
tracker.trackFailures();
// Simulated polling of `checkFailures`, an arbitrary number ( > 2 ) times
tracker.checkFailures(Infinity);
tracker.checkFailures(Infinity);
// should only track a single failure per event
expect(count).toBe(2);
@ -275,12 +256,9 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
// Indicate a second decryption, after having tracked the failure
eventDecrypted(tracker, decryptedEvent, Date.now());
tracker.trackFailures();
tracker.checkFailures(Infinity);
// should only track a single failure per event
expect(count).toBe(1);
@ -308,8 +286,6 @@ describe("DecryptionFailureTracker", function () {
// NB: This saves to localStorage specific to DFT
tracker.checkFailures(Infinity);
tracker.trackFailures();
// Simulate the browser refreshing by destroying tracker and creating a new tracker
// @ts-ignore access to private constructor
const secondTracker = new DecryptionFailureTracker(
@ -323,7 +299,6 @@ describe("DecryptionFailureTracker", function () {
eventDecrypted(secondTracker, decryptedEvent, Date.now());
secondTracker.checkFailures(Infinity);
secondTracker.trackFailures();
// should only track a single failure per event
expect(count).toBe(1);
@ -363,8 +338,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
//expect(counts['UnknownError']).toBe(1, 'should track one UnknownError');
expect(counts["OlmKeysNotSentError"]).toBe(2);
});
@ -400,8 +373,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(counts["OlmUnspecifiedError"]).toBe(3);
});
@ -423,8 +394,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
// should track remapped error code
expect(counts["XEDNI_EGASSEM_NWONKNU_MLO"]).toBe(1);
});
@ -488,8 +457,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(errorCodes).toEqual([
"OlmKeysNotSentError",
"OlmIndexError",
@ -546,8 +513,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(propertiesByErrorCode[error1].timeToDecryptMillis).toEqual(40000);
expect(propertiesByErrorCode[error2].timeToDecryptMillis).toEqual(-1);
expect(propertiesByErrorCode[error3].timeToDecryptMillis).toEqual(-1);
@ -576,14 +541,13 @@ describe("DecryptionFailureTracker", function () {
// long enough for the timers to fire, but we'll use fake timers just
// to be safe.
jest.useFakeTimers();
tracker.start(client);
await tracker.start(client);
// If the client fails to decrypt, it should get tracked
const failedDecryption = await createFailedDecryptionEvent();
client.emit(MatrixEventEvent.Decrypted, failedDecryption);
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(errorCount).toEqual(1);
@ -597,7 +561,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(errorCount).toEqual(1);
@ -655,8 +618,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(propertiesByErrorCode[error1].isMatrixDotOrg).toBe(true);
expect(propertiesByErrorCode[error1].cryptoSDK).toEqual("Rust");
@ -677,7 +638,6 @@ describe("DecryptionFailureTracker", function () {
tracker.addVisibleEvent(anotherFailure);
eventDecrypted(tracker, anotherFailure, now);
tracker.checkFailures(Infinity);
tracker.trackFailures();
expect(propertiesByErrorCode[error3].isMatrixDotOrg).toBe(false);
expect(propertiesByErrorCode[error3].cryptoSDK).toEqual("Legacy");
});
@ -707,7 +667,6 @@ describe("DecryptionFailureTracker", function () {
// Pretend "now" is Infinity
tracker.checkFailures(Infinity);
tracker.trackFailures();
// the time to decrypt should be relative to the first time we failed
// to decrypt, not the second