From 62601d657da3afa34a392e3b02ba8800785f0000 Mon Sep 17 00:00:00 2001 From: Luke Barnard Date: Fri, 15 Jun 2018 13:33:07 +0100 Subject: [PATCH] Implement DecryptionFailureTracker for less agressive tracking Instead of pinging Analytics once per failed decryption, add the failure to a list of failures and after a grace period, add it to a FIFO for tracking. On an interval, track a single failure from the FIFO. --- src/DecryptionFailureTracker.js | 124 +++++++++++++++++++++++ src/components/structures/MatrixChat.js | 16 +-- test/DecryptionFailureTracker-test.js | 128 ++++++++++++++++++++++++ 3 files changed, 262 insertions(+), 6 deletions(-) create mode 100644 src/DecryptionFailureTracker.js create mode 100644 test/DecryptionFailureTracker-test.js diff --git a/src/DecryptionFailureTracker.js b/src/DecryptionFailureTracker.js new file mode 100644 index 0000000000..0f86093209 --- /dev/null +++ b/src/DecryptionFailureTracker.js @@ -0,0 +1,124 @@ +/* +Copyright 2018 New Vector Ltd + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +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. +*/ + +class DecryptionFailure { + constructor(failedEventId) { + this.failedEventId = failedEventId; + this.ts = Date.now(); + } +} + +export default class DecryptionFailureTracker { + // Array of items of type DecryptionFailure. Every `CHECK_INTERVAL_MS`, this list + // is checked for failures that happened > `GRACE_PERIOD_MS` ago. Those that did + // are added to `failuresToTrack`. + failures = []; + + // Every TRACK_INTERVAL_MS (so as to spread the number of hits done on Analytics), + // one DecryptionFailure of this FIFO is removed and tracked. + failuresToTrack = []; + + // Spread the load on `Analytics` by sending at most 1 event per + // `TRACK_INTERVAL_MS`. + static TRACK_INTERVAL_MS = 1000; + + // Call `checkFailures` every `CHECK_INTERVAL_MS`. + static CHECK_INTERVAL_MS = 5000; + + // Give events a chance to be decrypted by waiting `GRACE_PERIOD_MS` before moving + // the failure to `failuresToTrack`. + static GRACE_PERIOD_MS = 5000; + + constructor(fn) { + if (!fn || typeof fn !== 'function') { + throw new Error('DecryptionFailureTracker requires tracking function'); + } + + this.trackDecryptionFailure = fn; + } + + eventDecrypted(e) { + if (e.isDecryptionFailure()) { + this.addDecryptionFailureForEvent(e); + } else { + // Could be an event in the failures, remove it + this.removeDecryptionFailuresForEvent(e); + } + } + + addDecryptionFailureForEvent(e) { + this.failures.push(new DecryptionFailure(e.getId())); + } + + removeDecryptionFailuresForEvent(e) { + this.failures = this.failures.filter((f) => f.failedEventId !== e.getId()); + } + + /** + * Start checking for and tracking failures. + * @return {function} a function that clears state and causes DFT to stop checking for + * and tracking failures. + */ + start() { + const checkInterval = setInterval( + () => this.checkFailures(Date.now()), + DecryptionFailureTracker.CHECK_INTERVAL_MS, + ); + + const trackInterval = setInterval( + () => this.trackFailure(), + DecryptionFailureTracker.TRACK_INTERVAL_MS, + ); + + return () => { + clearInterval(checkInterval); + clearInterval(trackInterval); + + this.failures = []; + this.failuresToTrack = []; + }; + } + + /** + * Mark failures that occured before nowTs - GRACE_PERIOD_MS as failures that should be + * tracked. Only mark one failure per event ID. + * @param {number} nowTs the timestamp that represents the time now. + */ + checkFailures(nowTs) { + const failuresGivenGrace = this.failures.filter( + (f) => nowTs > f.ts + DecryptionFailureTracker.GRACE_PERIOD_MS, + ); + + // Only track one failure per event + const dedupedFailuresMap = failuresGivenGrace.reduce( + (result, failure) => ({...result, [failure.failedEventId]: failure}), + {}, + ); + const dedupedFailures = Object.keys(dedupedFailuresMap).map((k) => dedupedFailuresMap[k]); + + this.failuresToTrack = [...this.failuresToTrack, ...dedupedFailures]; + } + + /** + * If there is a failure that should be tracked, call the given trackDecryptionFailure + * function with the first failure in the FIFO of failures that should be tracked. + */ + trackFailure() { + if (this.failuresToTrack.length > 0) { + this.trackDecryptionFailure(this.failuresToTrack.shift()); + } + } +} diff --git a/src/components/structures/MatrixChat.js b/src/components/structures/MatrixChat.js index da729a1a2d..7884829a76 100644 --- a/src/components/structures/MatrixChat.js +++ b/src/components/structures/MatrixChat.js @@ -23,6 +23,7 @@ import PropTypes from 'prop-types'; import Matrix from "matrix-js-sdk"; import Analytics from "../../Analytics"; +import DecryptionFailureTracker from "../../DecryptionFailureTracker"; import MatrixClientPeg from "../../MatrixClientPeg"; import PlatformPeg from "../../PlatformPeg"; import SdkConfig from "../../SdkConfig"; @@ -1308,14 +1309,17 @@ export default React.createClass({ } }); - // XXX: This will do a HTTP request for each Event.decrypted event - // if the decryption was a failure - cli.on("Event.decrypted", (e) => { - if (e.isDecryptionFailure()) { - Analytics.trackEvent('E2E', 'Decryption failure', 'ev.content.body: ' + e.getContent().body); - } + const dft = new DecryptionFailureTracker((failure) => { + // TODO: Pass reason for failure as third argument to trackEvent + Analytics.trackEvent('E2E', 'Decryption failure'); }); + const stopDft = dft.start(); + + // When logging out, stop tracking failures and destroy state + cli.on("Session.logged_out", stopDft); + cli.on("Event.decrypted", dft.eventDecrypted); + const krh = new KeyRequestHandler(cli); cli.on("crypto.roomKeyRequest", (req) => { krh.handleKeyRequest(req); diff --git a/test/DecryptionFailureTracker-test.js b/test/DecryptionFailureTracker-test.js new file mode 100644 index 0000000000..9d3b035bf5 --- /dev/null +++ b/test/DecryptionFailureTracker-test.js @@ -0,0 +1,128 @@ +/* +Copyright 2018 New Vector Ltd + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +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 expect from 'expect'; + +import DecryptionFailureTracker from '../src/DecryptionFailureTracker'; + +import { MatrixEvent } from 'matrix-js-sdk'; + +function createFailedDecryptionEvent() { + const event = new MatrixEvent({ + event_id: "event-id-" + Math.random().toString(16).slice(2), + }); + event._setClearData( + event._badEncryptedMessage(":("), + ); + return event; +} + +describe.only('DecryptionFailureTracker', function() { + it('tracks a failed decryption', function(done) { + const failedDecryptionEvent = createFailedDecryptionEvent(); + let trackedFailure = null; + const tracker = new DecryptionFailureTracker((failure) => { + trackedFailure = failure; + }); + + tracker.eventDecrypted(failedDecryptionEvent); + + // Pretend "now" is Infinity + tracker.checkFailures(Infinity); + + // Immediately track the newest failure, if there is one + tracker.trackFailure(); + + expect(trackedFailure).toNotBe(null, 'should track a failure for an event that failed decryption'); + + done(); + }); + + it('does not track a failed decryption where the event is subsequently successfully decrypted', (done) => { + const decryptedEvent = createFailedDecryptionEvent(); + const tracker = new DecryptionFailureTracker((failure) => { + expect(true).toBe(false, 'should not track an event that has since been decrypted correctly'); + }); + + tracker.eventDecrypted(decryptedEvent); + + // Indicate successful decryption: clear data can be anything where the msgtype is not m.bad.encrypted + decryptedEvent._setClearData({}); + tracker.eventDecrypted(decryptedEvent); + + // Pretend "now" is Infinity + tracker.checkFailures(Infinity); + + // Immediately track the newest failure, if there is one + tracker.trackFailure(); + done(); + }); + + it('only tracks a single failure per event, despite multiple failed decryptions for multiple events', (done) => { + const decryptedEvent = createFailedDecryptionEvent(); + const decryptedEvent2 = createFailedDecryptionEvent(); + + let count = 0; + const tracker = new DecryptionFailureTracker((failure) => count++); + + // Arbitrary number of failed decryptions for both events + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent2); + tracker.eventDecrypted(decryptedEvent2); + tracker.eventDecrypted(decryptedEvent2); + + // Pretend "now" is Infinity + tracker.checkFailures(Infinity); + + // Simulated polling of `trackFailure`, an arbitrary number ( > 2 ) times + tracker.trackFailure(); + tracker.trackFailure(); + tracker.trackFailure(); + tracker.trackFailure(); + + expect(count).toBe(2, count + ' failures tracked, should only track a single failure per event'); + + done(); + }); + + it('track failures in the order they occured', (done) => { + const decryptedEvent = createFailedDecryptionEvent(); + const decryptedEvent2 = createFailedDecryptionEvent(); + + const failures = []; + const tracker = new DecryptionFailureTracker((failure) => failures.push(failure)); + + // Indicate decryption + tracker.eventDecrypted(decryptedEvent); + tracker.eventDecrypted(decryptedEvent2); + + // Pretend "now" is Infinity + tracker.checkFailures(Infinity); + + // Simulated polling of `trackFailure`, an arbitrary number ( > 2 ) times + tracker.trackFailure(); + tracker.trackFailure(); + + expect(failures[0].failedEventId).toBe(decryptedEvent.getId(), 'the first failure should be tracked first'); + expect(failures[1].failedEventId).toBe(decryptedEvent2.getId(), 'the second failure should be tracked second'); + + done(); + }); +});