FEATURE: when we fail to ship topic timings attempt to retry (#10916)

FEATURE: when we fail to ship topic timings attempt to retry (#10916)

  • FEATURE: when we fail to ship topic timings attempt to retry

This change amends it so

  1. Topic timings are treated as background requests and subject to more aggressive rate limits.

  2. If we notice an error when we ship timings we back off exponentially

The commit allows 405, 429, 500, 501, 502, 503 and 504 errors to be retried.

500+ errors usually happen when self hosters are rebuilding or some other weird condition.

405 happens when site is in readonly. 429 happens when user is rate limited.

The retry cadence is hardcoded in AJAX_FAILURE_DELAYS, longest delay is 40 seconds, we may consider enlarging it.

After the last delay passes we give up and do not write timings to the server.

  • Address feedback
  • Omit promise, no need to use promises in sendNextConsolidatedTiming
  • Correct issue where >= -1 was used and > -1 was intended
  • Use objects for consolidated timings instead of Array
  • Stop using shift/unshift and instead use push / pop which are faster
  • Move consolidated timing initialization to constructor

  • Remove TODO and just console.warn if we have an issue

diff --git a/app/assets/javascripts/discourse/app/lib/screen-track.js b/app/assets/javascripts/discourse/app/lib/screen-track.js
index 028d63e..5ef5798 100644
--- a/app/assets/javascripts/discourse/app/lib/screen-track.js
+++ b/app/assets/javascripts/discourse/app/lib/screen-track.js
@@ -7,6 +7,9 @@ const PAUSE_UNLESS_SCROLLED = 1000 * 60 * 3;
 const MAX_TRACKING_TIME = 1000 * 60 * 6;
 const ANON_MAX_TOPIC_IDS = 5;
 
+const AJAX_FAILURE_DELAYS = [5000, 10000, 20000, 40000];
+const ALLOWED_AJAX_FAILURES = [405, 429, 500, 501, 502, 503, 504];
+
 export default class {
   constructor(topicTrackingState, siteSettings, session, currentUser) {
     this.topicTrackingState = topicTrackingState;
@@ -14,6 +17,7 @@ export default class {
     this.session = session;
     this.currentUser = currentUser;
     this.reset();
+    this._consolidatedTimings = [];
   }
 
   start(topicId, topicController) {
@@ -85,6 +89,104 @@ export default class {
     this._anonCallback = cb;
   }
 
+  consolidateTimings(timings, topicTime, topicId) {
+    let foundIndex = this._consolidatedTimings.findIndex(
+      (elem) => elem.topicId === topicId
+    );
+
+    if (foundIndex > -1) {
+      let found = this._consolidatedTimings[foundIndex];
+
+      const lastIndex = this._consolidatedTimings.length - 1;
+
+      if (foundIndex !== lastIndex) {
+        const last = this._consolidatedTimings[lastIndex];
+        this._consolidatedTimings[lastIndex] = found;
+        this._consolidatedTimings[lastIndex - 1] = last;
+      }
+
+      const oldTimings = found.timings;
+      Object.keys(oldTimings).forEach((id) => {
+        if (timings[id]) {
+          oldTimings[id] += timings[id];
+        }
+      });
+      found.topicTime += topicTime;
+      found.timings = Object.assign({}, timings, found.timings);
+    } else {
+      this._consolidatedTimings.push({ timings, topicTime, topicId });
+    }
+
+    return this._consolidatedTimings;
+  }
+
+  sendNextConsolidatedTiming() {
+    if (this._consolidatedTimings.length === 0) {
+      return;
+    }
+
+    if (this._inProgress) {
+      return;
+    }
+
+    if (
+      this._blockSendingToServerTill &&
+      this._blockSendingToServerTill > Date.now()
+    ) {
+      return;
+    }
+
+    this._ajaxFailures = this._ajaxFailures || 0;
+
+    const { timings, topicTime, topicId } = this._consolidatedTimings.pop();
+
+    this._inProgress = true;
+
+    ajax("/topics/timings", {
+      data: {
+        timings: timings,
+        topic_time: topicTime,
+        topic_id: topicId,
+      },
+      cache: false,
+      type: "POST",
+      headers: {
+        "X-SILENCE-LOGGER": "true",
+        "Discourse-Background": "true",
+      },
+    })
+      .then(() => {
+        this._ajaxFailures = 0;
+        const topicController = this._topicController;
+        if (topicController) {
+          const postNumbers = Object.keys(timings).map((v) => parseInt(v, 10));
+          topicController.readPosts(topicId, postNumbers);
+        }
+      })
+      .catch((e) => {
+        if (ALLOWED_AJAX_FAILURES.indexOf(e.jqXHR.status) > -1) {
+          const delay = AJAX_FAILURE_DELAYS[this._ajaxFailures];
+          this._ajaxFailures += 1;
+
+          if (delay) {
+            this._blockSendingToServerTill = Date.now() + delay;
+            // we did not send to the server, got to re-queue it
+            this.consolidateTimings(timings, topicTime, topicId);
+          }
+        }
+
+        if (window.console && window.console.warn) {
+          window.console.warn(
+            `Failed to update topic times for topic ${topicId} due to ${e.jqXHR.status} error`
+          );
+        }
+      })
+      .finally(() => {
+        this._inProgress = false;
+        this._lastFlush = 0;
+      });
+  }
+
   flush() {
     const newTimings = {};
     const totalTimings = this._totalTimings;
@@ -140,42 +242,8 @@ export default class {
 
     if (!$.isEmptyObject(newTimings)) {
       if (this.currentUser && !isTesting()) {
-        this._inProgress = true;
-
-        ajax("/topics/timings", {
-          data: {
-            timings: newTimings,
-            topic_time: this._topicTime,
-            topic_id: topicId,
-          },
-          cache: false,
-          type: "POST",
-          headers: {
-            "X-SILENCE-LOGGER": "true",
-          },
-        })
-          .then(() => {
-            const topicController = this._topicController;
-            if (topicController) {
-              const postNumbers = Object.keys(newTimings).map((v) =>
-                parseInt(v, 10)
-              );
-              topicController.readPosts(topicId, postNumbers);
-            }
-          })
-          .catch((e) => {
-            const error = e.jqXHR;
-            if (
-              error.status === 405 &&
-              error.responseJSON.error_type === "read_only"
-            ) {
-              return;
-            }
-          })
-          .finally(() => {
-            this._inProgress = false;
-            this._lastFlush = 0;
-          });
+        this.consolidateTimings(newTimings, this._topicTime, topicId);
+        this.sendNextConsolidatedTiming();
       } else if (this._anonCallback) {
         // Anonymous viewer - save to localStorage
         const storage = this.keyValueStore;
@@ -240,6 +308,11 @@ export default class {
       this.flush();
     }
 
+    if (!this._inProgress) {
+      // handles retries so there is no situation where we are stuck with a backlog
+      this.sendNextConsolidatedTiming();
+    }
+
     if (this.session.hasFocus) {
       this._topicTime += diff;
 
diff --git a/app/assets/javascripts/discourse/tests/unit/lib/screen-track-test.js b/app/assets/javascripts/discourse/tests/unit/lib/screen-track-test.js
new file mode 100644
index 0000000..178bca4
--- /dev/null
+++ b/app/assets/javascripts/discourse/tests/unit/lib/screen-track-test.js
@@ -0,0 +1,21 @@
+import { test, module } from "qunit";
+import ScreenTrack from "discourse/lib/screen-track";
+
+module("lib:screen-track");
+
+test("consolidateTimings", (assert) => {
+  const tracker = new ScreenTrack();
+
+  tracker.consolidateTimings({ 1: 10, 2: 5 }, 10, 1);
+  tracker.consolidateTimings({ 1: 5, 3: 1 }, 3, 1);
+  const consolidated = tracker.consolidateTimings({ 1: 5, 3: 1 }, 3, 2);
+
+  assert.deepEqual(
+    consolidated,
+    [
+      { timings: { 1: 15, 2: 5, 3: 1 }, topicTime: 13, topicId: 1 },
+      { timings: { 1: 5, 3: 1 }, topicTime: 3, topicId: 2 },
+    ],
+    "expecting consolidated timings to match correctly"
+  );
+});

GitHub sha: 110e9a45

1 Like

This commit appears in #10916 which was approved by eviltrout. It was merged by SamSaffron.