We are seeing pings on the server-side that are much bigger then they should be, up to 28MB. We should: * apply a size limit on pings submitted to TelemetryController and discard them * discard pings on disk that are above the size limit * track the different occurences in separate histograms, say: * TELEMETRY_PING_SIZE_CHECK_SUBMIT * TELEMETRY_PING_SIZE_CHECK_LOAD_PENDING * TELEMETRY_PING_SIZE_CHECK_LOAD_ARCHIVED

Also, we should at least track all ping sizes or at least the discarded ones.

Is there a bug about the underlying reason they are too large?

Not specifically, extensive BHR & Sql data was brought up before. We'll need that info as a pre-requisite to bug 1186986 anyway, filed bug 1187864.

Comment on attachment 8639857 [details] [diff] [review] part 1 - Discard pings wich are too big Review of attachment 8639857 [details] [diff] [review]: ----------------------------------------------------------------- ::: toolkit/components/telemetry/Histograms.json @@ +4694,5 @@ > "high": "300000", > "n_buckets": 20, > "description": "Time (ms) it takes for checking if the pending pings are over-quota" > }, > + "TELEMETRY_PING_SIZE_CHECK_SUBMIT": { I think you suggested some more obvious name here. How about TELEMETRY_PING_SIZE_EXCEEDED_SUBMIT/_LOAD_PENDING/_LOAD_ARCHIVED? ::: toolkit/components/telemetry/TelemetryController.jsm @@ +195,5 @@ > submitExternalPing: function(aType, aPayload, aOptions = {}) { > aOptions.addClientId = aOptions.addClientId || false; > aOptions.addEnvironment = aOptions.addEnvironment || false; > > + return Impl.submitExternalPing(aType, aPayload, aOptions); Don't really need to touch this here. Let's leave it for some change around this code. ::: toolkit/components/telemetry/TelemetrySend.jsm @@ +81,5 @@ > > // The age of a pending ping to be considered overdue (in milliseconds). > const OVERDUE_PING_FILE_AGE = 7 * 24 * 60 * MS_IN_A_MINUTE; // 1 week > > +// The maximum size a submitted ping can take have. "can have." @@ +82,5 @@ > // The age of a pending ping to be considered overdue (in milliseconds). > const OVERDUE_PING_FILE_AGE = 7 * 24 * 60 * MS_IN_A_MINUTE; // 1 week > > +// The maximum size a submitted ping can take have. > +const SUBMITTED_PING_MAXIMUM_SIZE_BYTES = 1024 * 1024; // 1 MB This can be more named more generic (say MAXIMUM_PING_SIZE_BYTES). Can this be one constant shared across modules? @@ +905,5 @@ > + // Check the size and drop pings which are too big. > + const pingSizeBytes = utf8Payload.length; > + if (pingSizeBytes > SUBMITTED_PING_MAXIMUM_SIZE_BYTES) { > + this._log.error("_doPing - submitted ping exceeds the size limit, size: " + pingSizeBytes); > + Telemetry.getHistogramById("TELEMETRY_PING_SIZE_CHECK_SUBMIT").add(); Maybe SEND instead of SUBMIT? @@ +911,5 @@ > + .add(Math.round(pingSizeBytes / 1024 / 1024)); > + // Make sure to remove this request from the pending pings requests by pretending > + // sending was successful. We don't need to call |request.abort()| as it was not > + // sent yet. > + onRequestFinished(true); This also means that we track it as a successful send etc. Why can't we just remove it and report a failure? ::: toolkit/components/telemetry/TelemetryStorage.jsm @@ +588,5 @@ > const path = getArchivedPingPath(id, new Date(data.timestampCreated), data.type); > const pathCompressed = path + "lz4"; > > + // Purge pings which are too big. > + let checkSize = Task.async(function*(path) { I think you don't need a Task here: let checkSize = function*() { ... }; ... yield* checkSize(); @@ +591,5 @@ > + // Purge pings which are too big. > + let checkSize = Task.async(function*(path) { > + const fileSize = (yield OS.File.stat(path)).size; > + if (fileSize > PING_FILE_MAXIMUM_SIZE_BYTES) { > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_PINGS_SIZE_MB") This is tracking a pretty different size measurement - compressed size on disk - vs. what we are measuring in _doPing() - uncompressed code units for utf8 representation. I think we want two (uncompressed size, compressed on-disk size) or three (_doPing size, pending on-disk size, archived on-disk size) probes. @@ +592,5 @@ > + let checkSize = Task.async(function*(path) { > + const fileSize = (yield OS.File.stat(path)).size; > + if (fileSize > PING_FILE_MAXIMUM_SIZE_BYTES) { > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_PINGS_SIZE_MB") > + .add(Math.round(fileSize / 1024 / 1024)); Shouldn't we floor these, so 1.6MB falls into ">=1 and <2"? @@ +775,5 @@ > + if (fileSize > PING_FILE_MAXIMUM_SIZE_BYTES) { > + this._log.error("_enforceArchiveQuota - removing file exceeding size limit " + file.path); > + // We just remove the ping from the disk, we don't bother removing it from pingList > + // since it won't contribute to the quota. > + yield this._removeArchivedPing(ping.id, ping.timestampCreated, ping.type); Can this reject? If yes, lets make sure to handle that gracefully and continue with the next ping.

(In reply to Georg Fritzsche [:gfritzsche] from comment #6) > @@ +911,5 @@ > > + .add(Math.round(pingSizeBytes / 1024 / 1024)); > > + // Make sure to remove this request from the pending pings requests by pretending > > + // sending was successful. We don't need to call |request.abort()| as it was not > > + // sent yet. > > + onRequestFinished(true); > > This also means that we track it as a successful send etc. > Why can't we just remove it and report a failure? I've changed this part a bit, we don't report it as successful anymore. > @@ +591,5 @@ > > + // Purge pings which are too big. > > + let checkSize = Task.async(function*(path) { > > + const fileSize = (yield OS.File.stat(path)).size; > > + if (fileSize > PING_FILE_MAXIMUM_SIZE_BYTES) { > > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_PINGS_SIZE_MB") > > This is tracking a pretty different size measurement - compressed size on > disk - vs. what we are measuring in _doPing() - uncompressed code units for > utf8 representation. > > I think we want two (uncompressed size, compressed on-disk size) or three > (_doPing size, pending on-disk size, archived on-disk size) probes. Good point, I've added 3 different probes.

Comment on attachment 8640506 [details] [diff] [review] part 1 - Discard pings wich are too big - v2 Review of attachment 8640506 [details] [diff] [review]: ----------------------------------------------------------------- Looks ok with the below resolved. ::: toolkit/components/telemetry/Histograms.json @@ +4698,5 @@ > + "TELEMETRY_PING_SIZE_EXCEEDED_SEND": { > + "alert_emails": ["telemetry-client-dev@mozilla.com"], > + "expires_in_version": "never", > + "kind": "count", > + "description": "Number of submitted Telemetry pings discarded because exceeding the maximum size" Nit: This should mention that we discarded before sending, not "submitted". @@ +4704,5 @@ > + "TELEMETRY_PING_SIZE_EXCEEDED_PENDING": { > + "alert_emails": ["telemetry-client-dev@mozilla.com"], > + "expires_in_version": "never", > + "kind": "count", > + "description": "Number of Telemetry pending pings discarded because exceeding the maximum size" Nit: "for exceeding" or "because they exceeded", ditto below. @@ +4728,5 @@ > + "high": "30", > + "n_buckets": 29, > + "description": "The size (MB) of the Telemetry archived, compressed, pings exceeding the maximum file size" > + }, > + "TELEMETRY_DISCARDED_SUBMITTED_PINGS_SIZE_MB": { Not "submitted" here either, we called it "send" above. ::: toolkit/components/telemetry/TelemetrySend.jsm @@ +907,5 @@ > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_SUBMITTED_PINGS_SIZE_MB") > + .add(Math.floor(pingSizeBytes / 1024 / 1024)); > + // We don't need to call |request.abort()| as it was not sent yet. > + this._pendingPingRequests.delete(id); > + return Promise.resolve(); We also need to remove the ping from disk, say: return TelemetryStorage.removePendingPing(id); We should have test coverage for that. ::: toolkit/components/telemetry/TelemetryStorage.jsm @@ +776,5 @@ > this._log.warn("_enforceArchiveQuota - Unable to find the size of ping " + ping.id); > continue; > } > > + // Enforce a maximum file size limit on pending pings. "archived pings" @@ +783,5 @@ > + // We just remove the ping from the disk, we don't bother removing it from pingList > + // since it won't contribute to the quota. > + yield this._removeArchivedPing(ping.id, ping.timestampCreated, ping.type) > + .catch(e => this._log.error("_enforceArchiveQuota - failed to remove archived ping" + ping.id)); > + this._archivedPings.delete(ping.id); Hm, shouldn't that just always be done in _removeArchivedPing()? Lets just move it there (as well as other occurences). @@ +1183,5 @@ > + yield this.removePendingPing(id); > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_PENDING_PINGS_SIZE_MB") > + .add(Math.floor(fileSize / 1024 / 1024)); > + Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_PENDING").add(); > + return Promise.reject(new Error("loadPendingPing - exceeded the maximum ping size: " + fileSize)); Throwing an error is the Task.jsm way of rejecting AFAIR, no need to return something specific.

(In reply to Georg Fritzsche [:gfritzsche] from comment #10) > ::: toolkit/components/telemetry/TelemetrySend.jsm > @@ +907,5 @@ > > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_SUBMITTED_PINGS_SIZE_MB") > > + .add(Math.floor(pingSizeBytes / 1024 / 1024)); > > + // We don't need to call |request.abort()| as it was not sent yet. > > + this._pendingPingRequests.delete(id); > > + return Promise.resolve(); > > We also need to remove the ping from disk, say: > return TelemetryStorage.removePendingPing(id); > > We should have test coverage for that. Persisted pings should not reach this branch due to |loadPendingPing| purging outsized pings. I've changed Promise.resolve to TelemetryStorage.removePendingPing.

(In reply to Alessio Placitelli [:Dexter] from comment #13) > (In reply to Georg Fritzsche [:gfritzsche] from comment #10) > > ::: toolkit/components/telemetry/TelemetrySend.jsm > > @@ +907,5 @@ > > > + Telemetry.getHistogramById("TELEMETRY_DISCARDED_SUBMITTED_PINGS_SIZE_MB") > > > + .add(Math.floor(pingSizeBytes / 1024 / 1024)); > > > + // We don't need to call |request.abort()| as it was not sent yet. > > > + this._pendingPingRequests.delete(id); > > > + return Promise.resolve(); > > > > We also need to remove the ping from disk, say: > > return TelemetryStorage.removePendingPing(id); > > > > We should have test coverage for that. > > Persisted pings should not reach this branch due to |loadPendingPing| > purging outsized pings. I've changed Promise.resolve to > TelemetryStorage.removePendingPing. Well, technically we check the "compressed" size in loadPendingPing and the uncompressed size here. We may drop additional pings at this location.

Comment on attachment 8640611 [details] [diff] [review] part 2 - Add test coverage Review of attachment 8640611 [details] [diff] [review]: ----------------------------------------------------------------- ::: toolkit/components/telemetry/tests/unit/test_PingAPI.js @@ +363,5 @@ > yield TelemetryStorage.testCleanupTaskPromise(); > yield TelemetryArchive.promiseArchivedPingList(); > yield checkArchive(); > + > + // Generate a 2MB string to use as part of the payload. Can we move this to a separate function? Side-note: we should move the archiving-specific tests out of this test-file, this was supposed to be about testing the externally available API. Can you file a follow-up on that? @@ +371,5 @@ > + const OVERSIZED_PING = { > + id: OVERSIZED_PING_ID, > + type: PING_TYPE, > + creationDate: (new Date()).toISOString(), > + test: LONG_STRING Let's use the `payload` field, not undocumented top-level fields. @@ +374,5 @@ > + creationDate: (new Date()).toISOString(), > + test: LONG_STRING > + }; > + // We manually archive the ping using TelemetryStorage. Using |TelemetryArchive.promiseArchivePing| > + // would otherwise compress it. Can't we just use a size that reliably compresses down to >1mb? Lz4 should compress consistently the same across platforms and that way we can avoid special-casing this scenario. Note that a highly uniform payload (all 'x') might compress down too much, maybe we'd need to change that. @@ +394,5 @@ > + yield TelemetryStorage.testCleanupTaskPromise(); > + yield TelemetryArchive.promiseArchivedPingList(); > + yield checkArchive(); > + > + // Make sure we're correctly updating the related histograms. Also check we don't count normal-sized pings. @@ +398,5 @@ > + // Make sure we're correctly updating the related histograms. > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_ARCHIVED").snapshot(); > + Assert.equal(h.sum, 1, "Telemetry must report 1 oversized ping in the archive."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_ARCHIVED_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report a 2MB, oversized, ping."); Even without compression, this is prone to failures - nothing guarantees that the on-disk-size matches the in-memory-size of our data across platforms. ::: toolkit/components/telemetry/tests/unit/test_TelemetrySend.js @@ +260,5 @@ > + yield TelemetrySend.testWaitOnOutgoingPings(); > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_SEND").snapshot(); > + Assert.equal(h.sum, 1, "Telemetry must report 1 oversized ping submitted."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_SEND_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report a 2MB, oversized, ping submitted."); Prone to failure, see the archived ping test. ::: toolkit/components/telemetry/tests/unit/test_TelemetrySendOldPings.js @@ +462,5 @@ > yield TelemetryController.reset(); > yield TelemetryStorage.testPendingQuotaTaskPromise(); > yield checkPendingPings(); > > + // Generate a 2MB string to use as part of the ping payload. Can we move that to a separate test function? @@ +503,5 @@ > + // Make sure we're correctly updating the related histograms. > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_PENDING").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report 1 oversized ping in the pending pings directory."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_PENDING_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 4, "Telemetry must report two 2MB, oversized, pings."); What about checking for normal pings to not show up in those histograms?

Comment on attachment 8641156 [details] [diff] [review] part 2 - Add test coverage - v2 Review of attachment 8641156 [details] [diff] [review]: ----------------------------------------------------------------- r=me with the below fixed. ::: toolkit/components/telemetry/tests/unit/head.js @@ +286,5 @@ > function promiseRejects(promise) { > return promise.then(() => false, () => true); > } > > +// Generates a random string of a specific length. "of at least a specific length", right? ::: toolkit/components/telemetry/tests/unit/test_PingAPI.js @@ +396,5 @@ > + // Make sure we're correctly updating the related histograms. > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_ARCHIVED").snapshot(); > + Assert.equal(h.sum, 1, "Telemetry must report 1 oversized ping in the archive."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_ARCHIVED_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, archivedPingSizeMB, "Telemetry must report the correct size for the oversized ping."); You don't want to check the sum, you want to check that there is 1 entry in the right bucket. ::: toolkit/components/telemetry/tests/unit/test_TelemetrySend.js @@ +250,5 @@ > + > + // Submit a ping of a normal size and check that we don't count it in the histogram. > + yield TelemetryController.submitExternalPing(TEST_PING_TYPE, { test: "test" }); > + yield TelemetrySend.testWaitOnOutgoingPings(); > + let h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_SEND").snapshot(); Also check that there is no value in PINGS_SIZE_MB yet while we're here - .sum==0 is enough here. @@ +259,5 @@ > + yield TelemetrySend.testWaitOnOutgoingPings(); > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_SEND").snapshot(); > + Assert.equal(h.sum, 1, "Telemetry must report 1 oversized ping submitted."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_SEND_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report a 2MB, oversized, ping submitted."); Don't check the sum, check that there is 1 entry in the "2" bucket. ::: toolkit/components/telemetry/tests/unit/test_TelemetrySendOldPings.js @@ +487,5 @@ > + // Make sure we're correctly updating the related histograms. > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_PENDING").snapshot(); > + Assert.equal(h.sum, 1, "Telemetry must report 1 oversized ping in the pending pings directory."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_PENDING_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report a 2MB, oversized, ping."); Don't check the sum, check that there is 1 entry in the "2" bucket. @@ +502,5 @@ > + // Make sure we're correctly updating the related histograms. > + h = Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_PENDING").snapshot(); > + Assert.equal(h.sum, 2, "Telemetry must report 1 oversized ping in the pending pings directory."); > + h = Telemetry.getHistogramById("TELEMETRY_DISCARDED_PENDING_PINGS_SIZE_MB").snapshot(); > + Assert.equal(h.sum, 4, "Telemetry must report two 2MB, oversized, pings."); Don't check the sum, check that there are 2 entries in the "2" bucket.

Try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=98115d7ac3e1

I had to rebase this a bit.

Comment on attachment 8641644 [details] [diff] [review] part 1 - Discard pings wich are too big - v4 Georg, since I had to rebase this and change a bit of |TelemetryStorage.loadPendingPing|, would you mind having a look again? When checking the file size in |loadPendingPing|, we increment the "TELEMETRY_PENDING_LOAD_FAILURE_READ" if the stat fails because the file was not found.

Comment on attachment 8641644 [details] [diff] [review] part 1 - Discard pings wich are too big - v4 Review of attachment 8641644 [details] [diff] [review]: ----------------------------------------------------------------- ::: toolkit/components/telemetry/TelemetryStorage.jsm @@ +1235,4 @@ > } > > + // Try to get the dimension of the ping. If that fails, update the histograms. > + let fileSize; You should initialize to 0 here, so it can't be undefined when hitting the fileSize check below. @@ +1239,5 @@ > + try { > + fileSize = (yield OS.File.stat(info.path)).size; > + } catch (e if e instanceof OS.File.Error && e.becauseNoSuchFile) { > + Telemetry.getHistogramById("TELEMETRY_PENDING_LOAD_FAILURE_READ").add(); > + throw e; Alternatively you could also just silence the error here, fall-through and let all failures consistently come from loadPingFile(). @@ +1251,5 @@ > + Telemetry.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_PENDING").add(); > + throw new Error("loadPendingPing - exceeded the maximum ping size: " + fileSize); > + } > + > + // Purge pings which are too big. Wrong comment, update to explain what this section does. @@ +1265,5 @@ > Telemetry.getHistogramById("TELEMETRY_PENDING_LOAD_FAILURE_PARSE").add(); > } > + throw e; > + }; > + return ping; Nit: Empty line before this one.

Thanks Georg.

https://hg.mozilla.org/integration/fx-team/rev/8d8aaf9af22d https://hg.mozilla.org/integration/fx-team/rev/0f05c264c1dc

https://hg.mozilla.org/mozilla-central/rev/8d8aaf9af22d https://hg.mozilla.org/mozilla-central/rev/0f05c264c1dc

Comment on attachment 8641673 [details] [diff] [review] part 1 - Discard pings wich are too big - v5 Approval Request Comment [Feature/regressing bug #]: Telemetry Unification [User impact if declined]: This is a shipping requirement for Unified Telemetry. It removes local pings that exceed a fixed size (1MB). This limits local storage/bandwidth/... use- It is part of a mostly fixup & diagnostic uplift batch for 41: http://bit.ly/1LYhA16 [Describe test coverage new/current, TreeHerder]: We have automated test-coverage, it baked on Nightly, we are tracking metrics for this via Telemetry. [Risks and why]: Low-risk of hidden issues, we haven't seen anything crop up on Nightly here. [String/UUID change made/needed]: None.

Comment on attachment 8641645 [details] [diff] [review] part 2 - Add test coverage - v4 Approval Request Comment [Feature/regressing bug #]: Telemetry Unification [User impact if declined]: This is a shipping requirement for Unified Telemetry. It removes local pings that exceed a fixed size (1MB). This limits local storage/bandwidth/... use- It is part of a mostly fixup & diagnostic uplift batch for 41: http://bit.ly/1LYhA16 [Describe test coverage new/current, TreeHerder]: We have automated test-coverage, it baked on Nightly, we are tracking metrics for this via Telemetry. [Risks and why]: Low-risk of hidden issues, we haven't seen anything crop up on Nightly here. [String/UUID change made/needed]: None.

Comment on attachment 8641673 [details] [diff] [review] part 1 - Discard pings wich are too big - v5 Approved as it has been on m-c for a few days now. Also, Unified Telemetry is a FF41 feature so the sooner we uplift we have more time to stabilize through Beta cycle.

This doesn't make sense to uplift yet without bug 1187340 approved. Otherwise we'll have rebase both redundantly.

https://hg.mozilla.org/releases/mozilla-aurora/rev/8ade7a203033 https://hg.mozilla.org/releases/mozilla-aurora/rev/e1614491cc94

(In reply to Georg Fritzsche [:gfritzsche] from comment #29) > This doesn't make sense to uplift yet without bug 1187340 approved. > Otherwise we'll have rebase both redundantly. Rebasing this patch turned out to be not overly problematic and we really want this.