Closed Bug 1828885 Opened 2 years ago Closed 2 years ago

Glean metrics test API returns value despite upload disabled

Categories

(Data Platform and Tools :: Glean: SDK, defect, P1)

Product:
Data Platform and Tools
Component:
Glean: SDK
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INVALID

People

(Reporter: raphael, Assigned: janerik)

References

Details

While working on a patch related to Client ID Regeneration on Fenix, I noticed that the Glean metrics test API returns values for metrics despite Glean upload being disabled in Fenix Settings. The metrics values are reset to null only after a Fenix restart.

Now I don't know if this is by design, but it certainly surprised me as a user because the Glean documentation states that metrics and pings data is cleared from the client and I can see that when telemetry is turned off, the change listener in DataChoicesFragment.kt stops the GleanMetricsService, which triggers Glean.setUploadEnabled(false).

I've tested this manually with a revision of Fenix that uses Glean SDK v52.4.2 on a virtual device (Pixel 3 API 30, Android 11.0 x86).

Below are steps and demo code to reproduce what I'm seeing:

  1. Create and add the following LifecycleEventObserver in FenixApplication.initializeGlean():

    /* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */

package org.mozilla.fenix.components.metrics.demo

import android.content.Context
import androidx.lifecycle.Lifecycle
import androidx.lifecycle.LifecycleEventObserver
import androidx.lifecycle.LifecycleOwner
import mozilla.components.support.base.log.logger.Logger
import org.mozilla.fenix.utils.Settings
import org.mozilla.fenix.GleanMetrics.Metrics
import org.mozilla.fenix.GleanMetrics.TopSites

private val logger = Logger("Demo")


class DemoLifecycleObserver(context: Context) : LifecycleEventObserver {
    private val settings = Settings(context)

    override fun onStateChanged(source: LifecycleOwner, event: Lifecycle.Event) {
        when (event) {
            Lifecycle.Event.ON_START -> {
                val telemetryEnabled = settings.isTelemetryEnabled
                logger.debug("Telemetry enabled pref $telemetryEnabled")

                val metricContextId = TopSites.contextId.testGetValue()
                logger.debug("Glean Metric value for TopSites.contextId $metricContextId")

                val metricCloseTabSettings = Metrics.closeTabSetting.testGetValue()
                logger.debug("Glean Metric value for Metrics.closeTabSetting $metricCloseTabSettings")
            }
            else -> {
                // For other lifecycle events, do nothing
            }
        }
    }
}

  2. Install and run the app on the virtual device in Android Studio

  3. Open the Logcat tab in Android Studio and filter by Demo

  4. Complete the Fenix onboarding experience by pressing Start browsing in the emulator

  5. Open the Fenix Settings, then Tabs and update Close tabs from Never to After one week

  6. Close the app using Android's Overview

  7. Start the app again on Android

  8. Open the Fenix Settings, then Data collection and toggle Usage and technical data from On to Off

  9. Press on the Android Home button to move the app to the background

  10. Move the app to the foreground using Android's Overview

  11. Close the app using Android's Overview

  12. Start the app again on Android

The new DemoLifecycleObserver logged several debug messages when the app became active (moved to foreground). We turn off telemetry in step 8. The log produced by step 10 shows that the values for TopSites.contextId and Metrics.closeTabSetting are not null. After the restart in step 11 and 12, the logs show that the values are now null.

See Also: → 1816530
Assignee: nobody → jrediger
Priority: -- → P1
❯ rg 'Telemetry enabled|Metric value' fenix.log
57:                   Demo  I  Telemetry enabled pref true
65:                   Demo  I  Glean Metric value for TopSites.contextId 6a13e67d-b09c-402e-83f1-b9351ef337ad
67:                   Demo  I  Glean Metric value for Metrics.closeTabSetting MANUAL
299:                   Demo  I  Telemetry enabled pref true
300:                         I  Glean Metric value for TopSites.contextId 6a13e67d-b09c-402e-83f1-b9351ef337ad
301:                         I  Glean Metric value for Metrics.closeTabSetting ONE_WEEK
430:                   Demo  I  Telemetry enabled pref false
431:                         I  Glean Metric value for TopSites.contextId null
432:                         I  Glean Metric value for Metrics.closeTabSetting null
518:                   Demo  I  Telemetry enabled pref false
519:                         I  Glean Metric value for TopSites.contextId null
520:                         I  Glean Metric value for Metrics.closeTabSetting null

I'm not able to reproduce this. I always get correctly null for those metrics after disabling data collection.

:raphael as I cannot reproduce this in a local test, is there anything further we should look into or close this?

Flags: needinfo?(rpierzina)

Hi Jan-Erik!

I just ran the steps again on git revision c3dda7c59c and can still reproduce the behavior above. I ran it 2 times.

Can somebody on your team try to reproduce the issue? Alternatively, we could jump on Zoom and I'll show you.

Flags: needinfo?(rpierzina) → needinfo?(jrediger)

Weird.
I'll try again, see if I can reproduce that then.

Flags: needinfo?(jrediger)

If it helps, it looks like I am able to reproduce this with an actual device (Android 8.0):

---------------------------- PROCESS STARTED (16629) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (16728) for package org.mozilla.fenix.debug ----------------------------
2023-05-04 11:51:48.298 16629-16629 demo                    org.mozilla.fenix.debug              D  Telemetry enabled pref true
2023-05-04 11:51:48.305 16629-16629 demo                    org.mozilla.fenix.debug              D  Glean Metric value for TopSites.contextId 51a1eae0-fd49-4b80-acff-ef9e1706ab71
2023-05-04 11:51:48.312 16629-16629 demo                    org.mozilla.fenix.debug              D  Glean Metric value for Metrics.closeTabSetting MANUAL
---------------------------- PROCESS STARTED (16816) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (16728) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (16816) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (16629) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (17062) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (17124) for package org.mozilla.fenix.debug ----------------------------
2023-05-04 11:52:47.465 17062-17062 demo                    org.mozilla.fenix.debug              D  Telemetry enabled pref true
2023-05-04 11:52:47.470 17062-17062 demo                    org.mozilla.fenix.debug              D  Glean Metric value for TopSites.contextId 51a1eae0-fd49-4b80-acff-ef9e1706ab71
2023-05-04 11:52:47.474 17062-17062 demo                    org.mozilla.fenix.debug              D  Glean Metric value for Metrics.closeTabSetting ONE_WEEK
---------------------------- PROCESS STARTED (17239) for package org.mozilla.fenix.debug ----------------------------
2023-05-04 11:53:16.450 17062-17062 demo                    org.mozilla.fenix.debug              D  Telemetry enabled pref false
2023-05-04 11:53:16.452 17062-17062 demo                    org.mozilla.fenix.debug              D  Glean Metric value for TopSites.contextId 51a1eae0-fd49-4b80-acff-ef9e1706ab71
2023-05-04 11:53:16.454 17062-17062 demo                    org.mozilla.fenix.debug              D  Glean Metric value for Metrics.closeTabSetting ONE_WEEK
---------------------------- PROCESS ENDED (17124) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (17239) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (17062) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (17434) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (17497) for package org.mozilla.fenix.debug ----------------------------
2023-05-04 11:53:28.341 17434-17434 demo                    org.mozilla.fenix.debug              D  Telemetry enabled pref false
2023-05-04 11:53:28.345 17434-17434 demo                    org.mozilla.fenix.debug              D  Glean Metric value for TopSites.contextId null
2023-05-04 11:53:28.353 17434-17434 demo                    org.mozilla.fenix.debug              D  Glean Metric value for Metrics.closeTabSetting null
---------------------------- PROCESS STARTED (17608) for package org.mozilla.fenix.debug ----------------------------

Ahh, so if you are using a debug version of the app, Fenix doesn't actually call stop on the GleanMetricsController, it only logs it: https://github.com/mozilla-mobile/firefox-android/blob/d3fecdd75f532a55ec07910d0360bf81267d2d34/fenix/app/src/main/java/org/mozilla/fenix/components/metrics/MetricController.kt#L93

So this may explain why you aren't seeing it disable the upload until after you quit the app and the value gets passed into Glean.initialize. You probably aren't seeing a deletion-request ping until then either...

The reason :janerik wasn't seeing this is because he's testing on a "release" version of Fenix nightly rather than a debug one

Good find, Travis! Interesting!

Travis is right, I use assembleNightly by default, which is a release build, and thus has the expected Telemetry behavior.
That mean's we can close this bug here as Glean is working correctly as expected.

That's okay with you, :raphael?

Flags: needinfo?(rpierzina)

Yes, I'm OK with closing this bug.

FWIW I set up Firefox on Android according to https://github.com/mozilla-mobile/firefox-android/blob/main/fenix/README.md#build-variants. I'm wondering if it's worth calling out that this behavior for the GleanMetricsController for debug build variants.

Flags: needinfo?(rpierzina)
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INVALID

(In reply to Raphael Pierzina [:raphael] UTC+01:00 from comment #10)

Yes, I'm OK with closing this bug.

FWIW I set up Firefox on Android according to https://github.com/mozilla-mobile/firefox-android/blob/main/fenix/README.md#build-variants. I'm wondering if it's worth calling out that this behavior for the GleanMetricsController for debug build variants.

I'd say this is worth re-filing, at least as a Fenix documentation bug. Or, since we drop debug build data on ingestion, it may be better for them to make the debug build behave more like the release build.

You need to log in before you can comment on or make changes to this bug.