From a41b818807a057360420e4047d7ab14ff7e5a34d Mon Sep 17 00:00:00 2001 From: brizental Date: Fri, 19 Nov 2021 10:50:37 +0100 Subject: [PATCH 1/3] Don't enqueue multiple stop command on uploader dispatcher The previous behaviour would enqueue a Stop command on the uploader dispatcher everytime a ping submit happening while the uploader was throttled or stopped due to other limitations. That resulted in the dispatcher being immediatelly stopped once it was resumed due to the throttling window being over, because the first command it would see would be a stop command. That could result in long lasting periods of time when the uploader was just stopped and not processing ping requests. --- glean/src/core/upload/index.ts | 16 +++++++++++----- glean/tests/unit/core/upload/index.spec.ts | 11 ++++++++++- 2 files changed, 21 insertions(+), 6 deletions(-) diff --git a/glean/src/core/upload/index.ts b/glean/src/core/upload/index.ts index a53c87f2a..38db3b188 100644 --- a/glean/src/core/upload/index.ts +++ b/glean/src/core/upload/index.ts @@ -93,6 +93,8 @@ class PingUploader implements PingsDatabaseObserver { private readonly platformInfo: PlatformInfo; // The server address we are sending pings to. private readonly serverEndpoint: string; + // Whether or not uploading is currently stopped due to limits having been hit. + private stopped = false; constructor( config: Configuration, @@ -132,16 +134,20 @@ class PingUploader implements PingsDatabaseObserver { const { state: rateLimiterState, remainingTime } = this.rateLimiter.getState(); if (rateLimiterState === RateLimiterState.Incrementing) { this.dispatcher.resume(); + this.stopped = false; } else { - // Stop the dispatcher respecting the order of the dispatcher queue, - // to make sure the Stop command is enqueued _after_ previously enqueued requests. - this.dispatcher.stop(false); + if(!this.stopped) { + // Stop the dispatcher respecting the order of the dispatcher queue, + // to make sure the Stop command is enqueued _after_ previously enqueued requests. + this.dispatcher.stop(false); + this.stopped = true; + } if (rateLimiterState === RateLimiterState.Throttled) { log( LOG_TAG, [ - "Attempted to upload a ping, but Glean is currently throttled.", + "Succesfully submitted a ping, but Glean is currently throttled.", `Pending pings will be processed in ${(remainingTime || 0) / 1000}s.` ], LoggingLevel.Debug @@ -151,7 +157,7 @@ class PingUploader implements PingsDatabaseObserver { log( LOG_TAG, [ - "Attempted to upload a ping, but Glean has reached maximum recoverable upload failures", + "Succesfully submitted a ping, but Glean has reached maximum recoverable upload failures", "for the current uploading window.", `Will retry in ${(remainingTime || 0) / 1000}s.` ], diff --git a/glean/tests/unit/core/upload/index.spec.ts b/glean/tests/unit/core/upload/index.spec.ts index fd593833b..bc15be836 100644 --- a/glean/tests/unit/core/upload/index.spec.ts +++ b/glean/tests/unit/core/upload/index.spec.ts @@ -25,7 +25,10 @@ const sandbox = sinon.createSandbox(); * @param pingName the name of the ping to fill the database with, defaults to "ping". * @returns The array of identifiers of the pings added to the database. */ -async function fillUpPingsDatabase(numPings: number, pingName = "ping"): Promise { +async function fillUpPingsDatabase( + numPings: number, + pingName = "ping" +): Promise { const ping = new PingType({ name: pingName, includeClientId: true, @@ -246,4 +249,10 @@ describe("PingUploader", function() { assert.ok("X-Client-Version" in headers); assert.ok("X-Telemetry-Agent" in headers); }); + + it("dispatcher is only once stopped if upload limits are hit", async function () { + const stopSpy = sandbox.spy(Glean["pingUploader"]["dispatcher"], "stop"); + await fillUpPingsDatabase(MAX_PINGS_PER_INTERVAL * 2); + assert.strictEqual(1, stopSpy.callCount); + }); }); From aa075bf2242dcad15f80154fc7e436f9d659b4cd Mon Sep 17 00:00:00 2001 From: brizental Date: Fri, 19 Nov 2021 11:09:22 +0100 Subject: [PATCH 2/3] Attend to review comments --- CHANGELOG.md | 1 + glean/tests/unit/core/upload/index.spec.ts | 16 ++++++++++++++-- 2 files changed, 15 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 15a4a75b2..f896b985a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ * Users may provide a folder name through the `VIRTUAL_ENV` environment variable. * If the user is inside an active virtualenv the `VIRTUAL_ENV` environment variable is already set by Python. See: https://docs.python.org/3/library/venv.html. * [#968](https://github.com/mozilla/glean.js/pull/968): Add runtime arguments type checking to `Glean.setUploadEnabled` API. +* [#970](https://github.com/mozilla/glean.js/pull/970): BUGFIX: Guarantee uploading is immediatelly resumed if the uploader has been stopped due to any of the uploading limits being hit. # v0.25.0 (2021-11-15) diff --git a/glean/tests/unit/core/upload/index.spec.ts b/glean/tests/unit/core/upload/index.spec.ts index bc15be836..ed271a7d4 100644 --- a/glean/tests/unit/core/upload/index.spec.ts +++ b/glean/tests/unit/core/upload/index.spec.ts @@ -250,9 +250,21 @@ describe("PingUploader", function() { assert.ok("X-Telemetry-Agent" in headers); }); - it("dispatcher is only once stopped if upload limits are hit", async function () { + it("dispatcher is only once stopped if upload limits are hit and is immediatelly restarted after", async function () { + const httpClient = new CounterUploader(); + await Glean.testResetGlean(testAppId, true, { httpClient }); + const stopSpy = sandbox.spy(Glean["pingUploader"]["dispatcher"], "stop"); - await fillUpPingsDatabase(MAX_PINGS_PER_INTERVAL * 2); + await fillUpPingsDatabase((MAX_PINGS_PER_INTERVAL * 2) - 1); + await Glean["pingUploader"].testBlockOnPingsQueue(); assert.strictEqual(1, stopSpy.callCount); + + // Reset the rate limiter so that we are not throttled anymore. + Glean["pingUploader"]["rateLimiter"]["reset"](); + + // Add one more ping to the queue so that uploading is resumed. + await fillUpPingsDatabase(1); + await Glean["pingUploader"].testBlockOnPingsQueue(); + assert.strictEqual(httpClient.count, MAX_PINGS_PER_INTERVAL * 2); }); }); From 3f892d92f76029e9ae3a95df520a3f2608ed6b9b Mon Sep 17 00:00:00 2001 From: brizental Date: Fri, 19 Nov 2021 11:11:08 +0100 Subject: [PATCH 3/3] Tweak the log messages just a tiny more --- glean/src/core/upload/index.ts | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/glean/src/core/upload/index.ts b/glean/src/core/upload/index.ts index 38db3b188..ad080a2fb 100644 --- a/glean/src/core/upload/index.ts +++ b/glean/src/core/upload/index.ts @@ -148,7 +148,7 @@ class PingUploader implements PingsDatabaseObserver { LOG_TAG, [ "Succesfully submitted a ping, but Glean is currently throttled.", - `Pending pings will be processed in ${(remainingTime || 0) / 1000}s.` + `Pending pings may be uploaded in ${(remainingTime || 0) / 1000}s.` ], LoggingLevel.Debug ); @@ -157,9 +157,9 @@ class PingUploader implements PingsDatabaseObserver { log( LOG_TAG, [ - "Succesfully submitted a ping, but Glean has reached maximum recoverable upload failures", - "for the current uploading window.", - `Will retry in ${(remainingTime || 0) / 1000}s.` + "Succesfully submitted a ping,", + "but Glean has reached maximum recoverable upload failures for the current uploading window.", + `May retry in ${(remainingTime || 0) / 1000}s.` ], LoggingLevel.Debug );