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 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.
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

Back to Bug 1945157 Comment 6