1809661 - Add telemetry to determine how long/often users see empty tabs message when syncing a new device

Status: RESOLVED FIXED

(Firefox :: Firefox View, task, P2)

Description

[Sarah Clements [:sclements]]

Since we want to eventually move towards a sync push notification when a new device is synced via Firefox View (bug 1806531), this telemetry will be useful to see how much the polling solution in bug 1792040 solves the issue (if at all).

Comment 1

[Sam Foster [:sfoster] (he/him)]

:sclements, I've got a working patch that records entries like:

firefoxview 	tab_pickup_empty 	elapsed 	294 

But looking at our other events telemetry, it looks like we're using a format like:

firefoxview 	synced_tabs 	tabs 	null 	{"count": "6"} 

.. I can follow suit, but I'm not sure what the reasoning is/was here. Do you have opinions on the event name/category/type/value we use for this?
tab_pickup_empty isn't great, we probably want something in there that better connotes "after a new device was added and there were 0 tabs, how long elapsed until we got > 0 tabs".

Comment 2

[Sarah Clements [:sclements]]

(In reply to Sam Foster [:sfoster] (he/him) from comment #1)

:sclements, I've got a working patch that records entries like:

firefoxview 	tab_pickup_empty 	elapsed 	294 

But looking at our other events telemetry, it looks like we're using a format like:

firefoxview 	synced_tabs 	tabs 	null 	{"count": "6"} 

.. I can follow suit, but I'm not sure what the reasoning is/was here. Do you have opinions on the event name/category/type/value we use for this?
tab_pickup_empty isn't great, we probably want something in there that better connotes "after a new device was added and there were 0 tabs, how long elapsed until we got > 0 tabs".

I didn't write any of that telemetry, so I can't speak to the reasoning. Its possible tab pickup could change so perhaps sticking with synced_tabs_<some sort of empty state> would make sense? No strong opinions either way though.

Comment 3

[Sam Foster [:sfoster] (he/him)]

Attachment: Bug 1809661 - Keep track of time spent with 0 tabs after a new device is added, and record a telemetry event with the time elapsed until new tabs are shown. r?kcochrane!

telemetry event with the time elapsed until new tabs are shown. r?kcochrane!

Comment 4

[Sam Foster [:sfoster] (he/him)]

STR:

• On desktop, In a new profile, open the Firefox View tab
• On a mobile device, open some tabs, but do not sign in and sync this device yet
• On desktop use the "Tab Pickup" buttons to sign in to FxA on the desktop device, and follow the steps to connect & sync the mobile device
• Switch over to Firefox View on the desktop

ER:

• You may see the 0 tabs "Nothing to see yet" empty state in the Tab Pickup container. Once the tabs sync from the newly added mobile device the first 3 should show up here.
• Sync could take anything up to a minute or more but may happen quickly enough to be already done by the time you open Firefox View.
• Check about:telemetry and search for synced_tabs_empty in the Events section
• You should see an entry with a value in seconds that agrees with the amount of time the Tab Pickup container showed "Nothing to see yet"

Comment 5

[Sam Foster [:sfoster] (he/him)]

Comment on attachment 9319048 [details]
Bug 1809661 - Keep track of time spent with 0 tabs after a new device is added, and record a telemetry event with the time elapsed until new tabs are shown. r?kcochrane!

I'll attach the data collection request as a sepatate .md file

Comment 6

[Sam Foster [:sfoster] (he/him)]

Attachment: Firefox View Data Collection Request.md

Comment 7

[Chris H-C :chutten]

Comment on attachment 9319384 [details]
Firefox View Data Collection Request.md

DATA COLLECTION REVIEW RESPONSE:

Is there or will there be documentation that describes the schema for the ultimate data set available publicly, complete and accurate?

Yes.

Is there a control mechanism that allows the user to turn the data collection on and off?

Yes. This collection can be controlled through Firefox's Preferences.

If the request is for permanent data collection, is there someone who will monitor the data over time?

No. This collection will expire in Firefox 120.

Using the category system of data types on the Mozilla wiki, what collection type of data do the requested measurements fall under?

Category 2, Interaction.

Is the data collection request for default-on or default-off?

Default on for all channels.

Does the instrumentation include the addition of any new identifiers?

No.

Is the data collection covered by the existing Firefox privacy notice?

Yes.

Does the data collection use a third-party collection tool?

No.

---

Result: datareview+

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d609e38d7305
Keep track of time spent with 0 tabs after a new device is added, and record a telemetry event with the time elapsed until new tabs are shown. r=kcochrane

Comment 9

[Natalia Csoregi [:nataliaCs]]

Backed out for failures on browser_tab_pickup_device_added_telemetry.js

• backout: https://hg.mozilla.org/integration/autoland/rev/10e01fbc2c9dc05809e7bcf7d2d9d651a4ed5336
• push: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&selectedTaskRun=BEKg2T5vTJSMLbP66JJBMw.0&revision=d609e38d730546bc0b4425ae1bd84683ed9dbe23
• failure log: https://treeherder.mozilla.org/logviewer?job_id=407174882&repo=autoland&lineNumber=12383

[task 2023-02-27T21:10:20.880Z] 21:10:20     INFO - Weve added a synced tab and updated the tab list, got snapshotEvents:{
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -   "parent": [
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -     [
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       220421,
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "firefoxview",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "synced_tabs",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "tabs",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       null,
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       {
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -         "count": "2"
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       }
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -     ],
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -     [
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       220422,
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "firefoxview",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "synced_tabs_empty",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "since_device_added",
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -       "32"
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -     ]
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO -   ]
[task 2023-02-27T21:10:20.881Z] 21:10:20     INFO - }
[task 2023-02-27T21:10:20.882Z] 21:10:20     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js | parent must be in snapshot. Has [parent]. - true == true - 
[task 2023-02-27T21:10:20.883Z] 21:10:20     INFO - Buffered messages finished
[task 2023-02-27T21:10:20.885Z] 21:10:20     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js | After filtering we must have the expected number of events. - 2 == 1 - {"filename":"resource://testing-common/TelemetryTestUtils.sys.mjs","name":"assertEvents","sourceId":574,"lineNumber":237,"columnNumber":12,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js","name":"test_device_added/<","sourceId":3171,"lineNumber":168,"columnNumber":24,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"test_device_added/<@chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js:168:24\n","nativeSavedFrame":{}},"formattedStack":"assertEvents@resource://testing-common/TelemetryTestUtils.sys.mjs:237:12\ntest_device_added/<@chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js:168:24\n","nativeSavedFrame":{}}
[task 2023-02-27T21:10:20.885Z] 21:10:20     INFO - Stack trace:
[task 2023-02-27T21:10:20.885Z] 21:10:20     INFO - resource://testing-common/TelemetryTestUtils.sys.mjs:assertEvents:237
[task 2023-02-27T21:10:20.885Z] 21:10:20     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js:test_device_added/<:168
[task 2023-02-27T21:10:20.886Z] 21:10:20     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_tab_pickup_device_added_telemetry.js | category in event firefoxview#synced_tabs#tabs must match. - "firefoxview" matches "firefoxview" -

Comment 10

[Natalia Csoregi [:nataliaCs]]

Other failures:

• TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_tab_pickup_visibility.js | A promise chain failed to handle a rejection: window.AWGetFeatureConfig is not a function - stack: retrieveRenderContent@resource://activity-stream/aboutwelcome/aboutwelcome.bundle.js:2195:36
• TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_searchMode_excludeResults.js | A promise chain failed to handle a rejection: this._internal._createRecentTabsList is not a function - stack: getRecentTabs@resource://services-sync/SyncedTabs.sys.mjs:332:27

Comment 11

[Sam Foster [:sfoster] (he/him)]

Thanks for the backout, I'll look into this. If there's a failure in browser_tab_pickup_visibility.js it would make sense for the telemetry test to also fail. I have no idea what the browser_searchMode_excludeResults.js failure is about, but hopefully fixing the first will clear up the rest.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/649252a67839
Keep track of time spent with 0 tabs after a new device is added, and record a telemetry event with the time elapsed until new tabs are shown. r=kcochrane

Comment 13

[Atila Butkovits]

Backed out for causing failures complaining about _createRecentTabsList

Backout link: https://hg.mozilla.org/integration/autoland/rev/456dca3da35f73dbfe45a68eda6adcfed43bc6dc

Push with failures: https://treeherder.mozilla.org/jobs?repo=autoland&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel&revision=649252a678394a69b2b6aa58aa63616cbe8e99d2&selectedTaskRun=c53CsR8aSRCZI6qggl8r_Q.0

Failure log: https://treeherder.mozilla.org/logviewer?job_id=408304188&repo=autoland&lineNumber=23051

Comment 14

[Sam Foster [:sfoster] (he/him)]

Thanks for the backout, I'm investigating. I see those urlbar tests use and stub SyncedTabs, and the firefoxview tests - including in my patch - use SyncedTabs as well, so there's surely a connection. I don't see it yet though..

Comment 15

[Sam Foster [:sfoster] (he/him)]

I can reproduce the failure this._internal._createRecentTabsList is not a function - stack: getRecentTabs@resource://services-sync/SyncedTabs.sys.mjs:327:27 if I run all of browser/components/firefoxview/tests/browser and browser/components/firefoxview/tests/browser but I've not yet been able to reduce it down any further.
The firefoxview tests do stub SyncedTabs methods, but we don't ever touch SyncedTabs._internal. Several of the urlbar tests replace SyncedTabs._internal with a mock and restore the original in a registerCleanupFunction function. So presumably something in my patch affecting the timing? Or changing some state in a way that causes these to fail later in the same test run?

In this try push, I added an assertion in a registerCleanupFunction to ensure SyncedTabs._internal._createRecentTabsList is a function at the end of each firefoxview test. and that seems to be the case. Yet, just a couple of tests into the urlbar suite, browser_searchMode_excludeResults.js again fails saying _createRecentTabsList isn't a function. I'm missing something...

Comment 16

[Sam Foster [:sfoster] (he/him)]

:standard8, looks like you might know these tests. Do you have any thoughts or suggestions on comment 15?

Comment 17

[Mark Banner (:standard8)]

Sorry, I don't really know those. I've only touched them for other reasons, I think you'd probably be better off seeing if Marco or Drew have any ideas.

Comment 18

[Marco Bonardo [:mak]]

Just a side note: you have a typo in updateViewVisiblity in the patch

First, what urlbar tests are doing looks scary, replacing the object with an incomplete one, then putting a sandbox on top (why, we have full control of the object...)... It would be much better to just use Sinon. So changing those tests to act in a nicer way would be fine!

What I suspect is happening is somehow your changes cause a late call to SyncedTabs.getRecentTabs(), that call ends up exactly during one of those urlbar tests, and that uses the incomplete replaced object. Or maybe your changes makes so a later use of the module causes a call to getRecentTabs(). I would reason on which of your changes may cause calls into getRecentTabs().
If you can reproduce the failure, I'd probably add a breakpoint on GetRecentTabs, or print a stack from there, so see who is invoking it, and then you may be able to walk back to the reason it now happens.

For example, it may be this observer https://searchfox.org/mozilla-central/rev/af78418c4b5f2c8721d1a06486cf4cf0b33e1e8d/browser/components/firefoxview/tab-pickup-list.mjs#21,28-30,66 listening to services.sync.tabs.changed? Maybe TabPickupList was not initialized before your patch?

firefox-view-tabs-setup-manager.sys.mjs also seems to be listening to stuff and calling into GetRecentTabs, you added a call to startWaitingForNewDeviceTabs and one to stopWaitingForTabs

Comment 19

[Sam Foster [:sfoster] (he/him)]

(In reply to Marco Bonardo [:mak] from comment #18)

Just a side note: you have a typo in updateViewVisiblity in the patch
So I do, thanks for spotting that.

firefox-view-tabs-setup-manager.sys.mjs also seems to be listening to stuff and calling into GetRecentTabs, you added a call to startWaitingForNewDeviceTabs and one to stopWaitingForTabs

Yeah it looks like stopWaitingForTabs is being called but should early-return when we're not actually waiting. Thanks for the pointers.

Comment 20

[Sam Foster [:sfoster] (he/him)]

Just a STR note, we arrive in this waiting for tabs from a newly-added-device state when you explicitly pair a new device - either from the firefox-view setup button, or from the device itself, or prefs etc. But we also get into this state if you sign in to a Firefox account which already had a 2nd device signed in and syncing tabs. In that case, we get the signed-in change via fxaccounts:device_connected as well as a fxaccounts:devicelist_updated notification where the device count will be 2 (or more.) We currently treat this as the device being added and tabs pending from that device.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/aceaa93c32aa
Keep track of time spent with 0 tabs after a new device is added, and record a telemetry event with the time elapsed until new tabs are shown. r=kcochrane

Comment 22

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/aceaa93c32aa