The reason for the intermittent can be observed in the following try, where additional logging was added to see when the glean data is reported and when it is checked by the test. https://treeherder.mozilla.org/logviewer?job_id=496795650&repo=try-comm-central&lineNumber=5267-5268 The message is laoded and the test proceeds to verify the glean data, but it has not yet been reported. This patch is waiting for the `MsgLoaded` event after normal messages have been selected, and for the `secureMsgLoaded` event for the encrypted messages. Only after these events have been seen, the glean data is verified.
Bug 1945157 Comment 6 Edit History
Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.
The reason for the intermittent can be observed in the following try, where additional logging was added to see when the glean data is reported and when it is checked by the test. https://treeherder.mozilla.org/logviewer?job_id=496795650&repo=try-comm-central&lineNumber=5267-5268 The message is loaded and the test proceeds to verify the glean data, but it has not yet been reported. This patch is waiting for the `MsgLoaded` event after normal messages have been selected, and for the `secureMsgLoaded` event after encrypted messages have been selected. Only after these events have been seen, the glean data is verified. The same event triggers the glean data report.
The glean data is reported after the `secureMsgLoaded` event has been issued (and apparently also after the message has been marked as read). The function `select_click_row()` is waiting for the load of the clicked message, but not for the mensioned event, which is issued later. There is a high probability, that the next message is clicked, before the reporting could be initiated. This patch is waiting for the `MsgLoaded` event after normal messages have been selected, and for the `secureMsgLoaded` event after encrypted messages have been selected. Only after these events have been seen (= the glean data has been reported), the next message is clicked.
While trying to understand the intermittent fail, it was observed that the test is not testing what it should and that the implementation to report telemetry data is broken. This patch aims to fix the test and the implementation without changing the intention of the original implementation. 1. What is wrong with the implementation? Logs (see [1]) from a test with more debug output shows, that we record two records for the first encrypted S/MIME message, but none for the second. The OpenPGP message is recorded as `is_encrypted: false`. This is caused by the load process of encrypted messages, which get reloaded multiple times when they are displayed. This clears the read flag and the so far collected telemetry data. Any incoming data after a reload which cleared the read flag is ignored. 2. Why is the test still passing, if there is no telemetry for the second message and the OpenPGP message is marked as "not encrypted"? The test is using a faulty filter to reduce the seen events to encrypted messages only. The statement assumes that the glean entry for `is_encrypted` is a boolean, but is in fact a string (either `"true"` or `"false"`). The filter condition therefore returns `true` for `is_encrypted` being set to `"false"`. 3. What does this patch do? The telemetry data is no longer cleared on reload, but only if a different message is loaded (idea from Geoff, see [2]). When data is collected, we initiate a timer to process the collected data, but the timer gets reset each time a new telemetry information comes in. This will give us a single telemetry set per message with the required information (security, is_encrypted and is_signed). The intermittent is fixed by introducing a new `CustomEvent`, which tells the test and other consumers, when telemetry data has been processed. [1] : https://phabricator.services.mozilla.com/D239902#8284314 [2] : https://phabricator.services.mozilla.com/D197795#7213166