search

mozilla-mobile / fenix

⚠️ Fenix (Firefox for Android) moved to a new repository. It is now developed and maintained as part of: https://github.com/mozilla-mobile/firefox-android
https://github.com/mozilla-mobile/firefox-android
Mozilla Public License 2.0
6.47k stars 1.27k forks source link

[Bug] fenix telemetry ping debug/exfiltration #3181

Closed bdekoz closed 4 years ago

bdekoz commented 5 years ago

Steps to reproduce

checkout mozilla-mobile/fenix build it install fenix apk on android device enable USB debugging, connect device to workstation

1) on workstation: enter 'adb devices' in terminal (make sure connected, when device is continue...) 2) on workstation, enter in terminal: adb shell am start W n org.mozilla.fenix.debug/org.mozilla.fenix.IntentReceiverActivity a android.intent.action.VIEW d https://www.theguardian.com/world/all 3) on android device: wait for browser screen to come up 4) set timer for 2 minutes, after it has elapsed, continue 5) on workstation, enter in terminal #1: adb logcat -c; adb logcat 6) on workstation, enter in terminal #2: adb shell am start n org.mozilla.fenix.debug/mozilla.components.service.glean.debug.GleanDebugActivity ez logPings true -es sendPing metrics

Expected behavior

on workstation, in terminal #1, expect adb logcat spew with metric in stringified JSON format

I'd gotten this to work on an older build with the 'baseline' ping request, but using the current top of tree this appears broken as well. aka:

            * beginning of system

06-05 12:13:25.436 1171 1432 I ActivityManager: START u0 {flg=0x10000000 cmp=org.mozilla.fenix.debug/mozilla.components.service.glean.debug.GleanDebugActivity (has extras)} from uid 2000 06-05 12:13:25.442 774 774 D android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON 06-05 12:13:25.450 7284 7284 W ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@975688c 06-05 12:13:25.466 7284 7284 E glean/GleanDebugActivity: Glean is not initialized. It may be disabled by the application. 06-05 12:13:25.501 774 774 D android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH OFF

previous: 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: Glean ping to URL: /submit/org-mozilla-fenix/baseline/1/23f40e44-7a1d-4709-bcd7-cbcfe68b206a 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: { 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "metrics": { 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "string": { 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "glean.baseline.locale": "en-US" 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: } 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: }, 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "ping_info": { 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "ping_type": "baseline", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "seq": 3, 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "start_time": "2019-06-04T15:50-07:00", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "end_time": "2019-06-04T15:54-07:00" 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: }, 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "client_info": { 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "telemetry_sdk_build": "0.55.0", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "first_run_date": "2019-05-21-07:00", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "os": "Android", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "android_sdk_version": "28", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "os_version": "9", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "device_manufacturer": "Google", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "device_model": "Pixel 2", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "architecture": "arm64-v8a", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "app_channel": "release", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "app_build": "11541308", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "app_display_version": "1.0.1923", 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: "client_id": "dbeb11c6-55cb-4b7e-a260-abe4ec8d4b00" 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: } 06-04 15:54:52.921 20215 20713 D glean/HttpPingUploader: }

Actual behavior

06-05 12:09:14.440 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 692s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut}

            * beginning of system

06-05 12:08:36.230 1171 1171 V SettingsProvider: Notifying for 0: content://settings/system/screen_brightness 06-05 12:09:14.788 1171 5588 I ActivityManager: START u0 {flg=0x10000000 cmp=org.mozilla.fenix.debug/mozilla.components.service.glean.debug.GleanDebugActivity (has extras)} from uid 2000 06-05 12:09:14.800 774 774 D android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON 06-05 12:09:14.806 774 774 D android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON 06-05 12:09:14.829 7284 7284 I lla.fenix.debu: Late-enabling -Xcheck:jni 06-05 12:09:14.830 1171 1210 I ActivityManager: Start proc 7284:org.mozilla.fenix.debug/u0a153 for activity org.mozilla.fenix.debug/mozilla.components.service.glean.debug.GleanDebugActivity 06-05 12:09:14.896 7284 7284 I lla.fenix.debu: The ClassLoaderContext is a special shared library. 06-05 12:09:15.739 7284 7284 I AppServices: Using viaduct_lib_name: fenix 06-05 12:09:15.783 7284 7284 I AppServices: Using rc_log_ffi_lib_name: fenix 06-05 12:09:15.788 7284 7284 I rc_log_ffi::ios: rc_log adapter initialized! 06-05 12:09:15.789 7284 7304 D App : Experiments active: {use-homescreen-tips=false, AAtest=false, use-gecko=false, use-gecko-nightly=true, use-homescreen-tips-nightly=true} 06-05 12:09:15.792 7284 7304 D NetworkSecurityConfig: No Network Security Config specified, using platform default 06-05 12:09:15.821 7284 7284 D App : DebugMetricController: start 06-05 12:09:15.824 7284 7284 D SoLoader: init start 06-05 12:09:15.824 7284 7284 D SoLoader: adding system library source: /vendor/lib 06-05 12:09:15.824 7284 7284 D SoLoader: adding system library source: /system/lib 06-05 12:09:15.825 7284 7284 D SoLoader: adding application source: com.facebook.soloader.DirectorySoSource[root = /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm flags = 0] 06-05 12:09:15.827 7284 7284 D SoLoader: adding backup source from : com.facebook.soloader.ApkSoSource[root = /data/data/org.mozilla.fenix.debug/lib-main flags = 1] 06-05 12:09:15.827 7284 7284 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /system/lib flags = 2] 06-05 12:09:15.827 7284 7284 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /vendor/lib flags = 2] 06-05 12:09:15.827 7284 7284 D SoLoader: Preparing SO source: com.facebook.soloader.DirectorySoSource[root = /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm flags = 0] 06-05 12:09:15.827 7284 7284 D SoLoader: Preparing SO source: com.facebook.soloader.ApkSoSource[root = /data/data/org.mozilla.fenix.debug/lib-main flags = 1] 06-05 12:09:15.828 7284 7284 V fb-UnpackingSoSource: locked dso store /data/user/0/org.mozilla.fenix.debug/lib-main 06-05 12:09:15.829 7284 7284 I fb-UnpackingSoSource: dso store is up-to-date: /data/user/0/org.mozilla.fenix.debug/lib-main 06-05 12:09:15.829 7284 7284 V fb-UnpackingSoSource: releasing dso store lock for /data/user/0/org.mozilla.fenix.debug/lib-main 06-05 12:09:15.830 7284 7284 D SoLoader: init finish: 4 SO sources prepared 06-05 12:09:15.830 7284 7284 D SoLoader: init exiting 06-05 12:09:15.833 7284 7315 D SoLoader: About to load: libflipperfb.so 06-05 12:09:15.833 7284 7315 D SoLoader: libflipperfb.so not found on /data/data/org.mozilla.fenix.debug/lib-main 06-05 12:09:15.834 7284 7315 D SoLoader: libflipperfb.so found on /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm 06-05 12:09:15.834 7284 7315 D SoLoader: Not resolving dependencies for libflipperfb.so 06-05 12:09:15.838 7284 7315 D SoLoader: Loaded: libflipperfb.so 06-05 12:09:15.838 7284 7315 D SoLoader: About to load: libflipper.so 06-05 12:09:15.838 7284 7315 D SoLoader: libflipper.so not found on /data/data/org.mozilla.fenix.debug/lib-main 06-05 12:09:15.838 7284 7315 D SoLoader: libflipper.so found on /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm 06-05 12:09:15.838 7284 7315 D SoLoader: Not resolving dependencies for libflipper.so 06-05 12:09:15.852 7284 7315 D SoLoader: Loaded: libflipper.so 06-05 12:09:15.874 7284 7284 W lla.fenix.debu: Accessing hidden field Landroid/view/View;->mKeyedTags:Landroid/util/SparseArray; (light greylist, reflection) 06-05 12:09:15.874 7284 7284 W lla.fenix.debu: Accessing hidden field Landroid/view/View;->mListenerInfo:Landroid/view/View$ListenerInfo; (light greylist, reflection) 06-05 12:09:15.874 7284 7284 W lla.fenix.debu: Accessing hidden field Landroid/view/View$ListenerInfo;->mOnClickListener:Landroid/view/View$OnClickListener; (light greylist, reflection) 06-05 12:09:15.878 7284 7284 I flipper : flipper: FlipperClient::addPlugin Inspector 06-05 12:09:15.878 7284 7284 I flipper : flipper: FlipperClient::addPlugin LeakCanary 06-05 12:09:15.879 7284 7284 I flipper : flipper: FlipperClient::addPlugin Preferences 06-05 12:09:15.887 7284 7323 D libEGL : loaded /vendor/lib/egl/libEGL_adreno.so 06-05 12:09:15.891 7284 7323 E libc : Access denied finding property "vendor.debug.egl.profiler" 06-05 12:09:15.887 7284 7284 W org.mozilla.fenix.debug: type=1400 audit(0.0:1168): avc: denied { read } for comm=45474C20496E6974 name="u:object_r:vendor_default_prop:s0" dev="tmpfs" ino=8721 scontext=u:r:untrusted_app:s0:c153,c256,c512,c768 tcontext=u:object_r:vendor_default_prop:s0 tclass=file permissive=0 06-05 12:09:15.893 7284 7323 D libEGL : loaded /vendor/lib/egl/libGLESv1_CM_adreno.so 06-05 12:09:15.898 7284 7284 E glean/GleanDebugActivity: Glean is not initialized. It may be disabled by the application. 06-05 12:09:15.910 7284 7323 D libEGL : loaded /vendor/lib/egl/libGLESv2_adreno.so 06-05 12:09:15.927 1171 1208 I ActivityManager: Killing 6476:com.android.chrome:webview_service/u0a75 (adj 906): empty #17 06-05 12:09:15.927 1171 1211 W libprocessgroup: kill(-6476, 9) failed: No such process 06-05 12:09:15.943 713 713 I Zygote : Process 6476 exited due to signal (9) 06-05 12:09:15.972 1171 1211 W libprocessgroup: kill(-6476, 9) failed: No such process 06-05 12:09:15.972 1171 1211 I libprocessgroup: Successfully killed process cgroup uid 10075 pid 6476 in 45ms 06-05 12:09:16.052 7284 7284 D GeckoThread: State changed to LAUNCHED 06-05 12:09:16.062 7284 7327 I GeckoThread: preparing to run Gecko 06-05 12:09:16.077 7284 7284 D GeckoRuntime: Lifecycle: onCreate 06-05 12:09:16.082 7284 7327 D GeckoThread: State changed to MOZGLUE_READY 06-05 12:09:16.098 774 774 D android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH OFF 06-05 12:09:16.138 7284 7327 W Settings: Setting animator_duration_scale has moved from android.provider.Settings.System to android.provider.Settings.Global, returning read-only global URI. 06-05 12:09:16.141 7284 7327 E GeckoLibLoad: Load sqlite start 06-05 12:09:16.170 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libnss3.so: unhandled flags #8 not handled 06-05 12:09:16.181 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libnss3.so: Relocation to NULL @0x0011dffc for symbol "cxa_type_match" 06-05 12:09:16.181 7284 7327 E GeckoLibLoad: Load sqlite done 06-05 12:09:16.182 7284 7327 E GeckoLibLoad: Load nss start 06-05 12:09:16.182 7284 7327 E GeckoLibLoad: Load nss done 06-05 12:09:16.184 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libxul.so: unhandled flags #8 not handled 06-05 12:09:16.189 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/liblgpllibs.so: unhandled flags #8 not handled 06-05 12:09:16.230 606 634 W SurfaceFlinger: Attempting to set client state on removed layer: Splash Screen org.mozilla.fenix.debug#0 06-05 12:09:16.230 606 634 W SurfaceFlinger: Attempting to destroy on removed layer: Splash Screen org.mozilla.fenix.debug#0 06-05 12:09:16.244 7284 7327 E GeckoLibLoad: Loaded libs in 61.172819ms total, 23ms(110ms) user, 3ms(3ms) system, 7(7) faults 06-05 12:09:16.249 7284 7327 D GeckoThread: State changed to LIBS_READY 06-05 12:09:16.250 7284 7327 W GeckoThread: zerdatime 105308057 - runGecko 06-05 12:09:16.297 7284 7327 D GeckoProfile: Found profile dir. 06-05 12:09:16.614 7284 7327 I Gecko:DumpUtils: Fifo watcher disabled via pref. 06-05 12:09:16.759 7284 7327 D GeckoSysInfo: System memory: 3656MB. 06-05 12:09:16.760 7284 7327 W lla.fenix.debu: Accessing hidden method Landroid/os/MessageQueue;->next()Landroid/os/Message; (light greylist, JNI) 06-05 12:09:16.760 7284 7327 W lla.fenix.debu: Accessing hidden field Landroid/os/MessageQueue;->mMessages:Landroid/os/Message; (light greylist, JNI) 06-05 12:09:16.762 7284 7327 D GeckoThread: State changed to JNI_READY 06-05 12:09:16.988 7284 7284 D GeckoNetworkManager: Incoming event enableNotifications for state OffNoListeners -> OffWithListeners 06-05 12:09:16.991 7284 7284 D GeckoNetworkManager: New network state: UP, WIFI, WIFI 06-05 12:09:17.149 7284 7327 I Gecko : 1559761757143 addons.xpi WARN List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [nsIXPCComponents_Utils.readUTF8URI]" nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)" location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 221" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:221 06-05 12:09:17.149 7284 7327 I Gecko : callProvider()@resource://gre/modules/AddonManager.jsm:19 06-05 12:09:17.149 7284 7327 I Gecko : _startProvider()@resource://gre/modules/AddonManager.jsm:40 06-05 12:09:17.149 7284 7327 I Gecko : startup()@resource://gre/modules/AddonManager.jsm:58 06-05 12:09:17.149 7284 7327 I Gecko : startup()@resource://gre/modules/AddonManager.jsm:290 06-05 12:09:17.149 7284 7327 I Gecko : observe()@resource://gre/modules/addonManager.js:2 06-05 12:09:17.159 7284 7327 I Gecko : 1559761757159 addons.xpi WARN No list of valid system add-ons found. 06-05 12:09:17.202 7284 7327 D GeckoThread: State changed to PROFILE_READY 06-05 12:09:17.346 7284 7327 W GeckoEventDispatcher: No listener for AndroidCastDevice:SyncDevice 06-05 12:09:17.351 7284 7327 I Gecko : * nsDNSServiceDiscovery.js : nsDNSServiceDiscovery 06-05 12:09:17.408 7284 7327 I Gecko : Attempting load of libEGL.so 06-05 12:09:17.410 7284 7327 I Adreno : QUALCOMM build : 6fb5a5b, Ife855c4895 06-05 12:09:17.410 7284 7327 I Adreno : Build Date : 08/21/18 06-05 12:09:17.410 7284 7327 I Adreno : OpenGL ES Shader Compiler Version: EV031.25.00.00 06-05 12:09:17.410 7284 7327 I Adreno : Local Branch : Googledrop_0815 06-05 12:09:17.410 7284 7327 I Adreno : Remote Branch : 06-05 12:09:17.410 7284 7327 I Adreno : Remote Branch : 06-05 12:09:17.410 7284 7327 I Adreno : Reconstruct Branch : 06-05 12:09:17.410 7284 7327 I Adreno : Build Config : S L 4.0.10 AArch32 06-05 12:09:17.415 7284 7327 I Adreno : PFP: 0x005ff110, ME: 0x005ff066 06-05 12:09:17.425 7284 7327 I ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 1 06-05 12:09:17.425 7284 7327 I ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 0 06-05 12:09:17.476 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 695s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:17.821 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libsoftokn3.so: unhandled flags #8 not handled 06-05 12:09:17.822 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libsoftokn3.so: Relocation to NULL @0x00021ffc for symbol "cxa_type_match" 06-05 12:09:17.823 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libfreebl3.so: unhandled flags #8 not handled 06-05 12:09:17.824 7284 7327 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libfreebl3.so: Relocation to NULL @0x0003cffc for symbol "cxa_type_match" 06-05 12:09:17.847 7284 7365 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libnssckbi.so: unhandled flags #8 not handled 06-05 12:09:17.860 7284 7365 W GeckoLinker: /data/app/org.mozilla.fenix.debug-Hy70nQFFOPQ178VEwx_jbA==/lib/arm/libnssckbi.so: Relocation to NULL @0x00051ffc for symbol "cxa_type_match" 06-05 12:09:20.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 698s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:23.441 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 701s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:26.478 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 704s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:29.440 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 707s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:32.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 710s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:35.453 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 713s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:38.450 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 716s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:41.450 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 719s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:43.969 757 757 I /vendor/bin/hw/android.hardware.health@2.0-service.wahoo: SRAM data: 2610000 06-05 12:09:43.992 1788 1788 E QtiImsExtUtils: getConfigForPhoneId phoneId is invalid 06-05 12:09:43.992 1788 1788 E QtiImsExtUtils: isCarrierConfigEnabled bundle is null 06-05 12:09:44.454 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 722s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:47.454 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 725s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:50.478 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 728s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:53.464 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 731s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:56.466 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 734s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:09:59.448 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 737s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:02.465 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 740s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:05.468 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 743s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:07.032 2102 2114 I .gms.persisten: Background concurrent copying GC freed 411924(17MB) AllocSpace objects, 22(1020KB) LOS objects, 50% free, 17MB/35MB, paused 192us total 191.388ms 06-05 12:10:08.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 746s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:10.463 829 888 I CHRE : @ 105364.891: [ImuCal] [NanoSensorCal:GYRO_RPS] Offset | Temperature [C]: -0.001851, 0.004996, 0.005733 | 22.55 06-05 12:10:10.463 829 888 I CHRE : @ 105364.891: [ImuCal] [NanoSensorCal:GYRO_RPS] Temp Sensitivity: 0.000324, 0.000297, -0.001147 06-05 12:10:10.463 829 888 I CHRE : @ 105364.891: [ImuCal] [NanoSensorCal:GYRO_RPS] Temp Intercept: 0.009505, 0.002245, 0.032287 06-05 12:10:10.508 1171 1171 V SettingsProvider: Notifying for 0: content://settings/system/screen_brightness 06-05 12:10:11.446 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 749s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:14.476 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 752s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:17.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 755s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:20.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 758s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:23.459 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 761s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:26.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 764s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:29.442 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 767s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:32.477 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 770s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:35.440 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 773s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:38.454 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 776s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:41.439 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 779s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:43.967 757 757 I /vendor/bin/hw/android.hardware.health@2.0-service.wahoo: SRAM data: 2610000 06-05 12:10:44.006 1788 1788 E QtiImsExtUtils: getConfigForPhoneId phoneId is invalid 06-05 12:10:44.006 1788 1788 E QtiImsExtUtils: isCarrierConfigEnabled bundle is null 06-05 12:10:44.480 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 782s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:45.240 1171 25317 D ApfFilter: (wlan0): Expiring RA fe80::259:dcff:feec:c060 -> ff02::1 1800s 2620:101:80fb:232::/64 2592000s/604800s DNS 400s 2001:4860:4860::8888 2001:4860:4860::8844 06-05 12:10:47.479 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 785s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:50.441 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 788s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, startTimeMs=104613295, waitTimeMs=0, timedOut} 06-05 12:10:53.464 6745 6797 W CelloCake: [CelloTaskRunner6a9c4f87-monitoring0] [Account=6a9c4f87:Task=90406201]Slow task still running after 791s. resetCache(){account=6a9c4f87, submitTimeMs=104613295, s

Device information

┆Issue is synchronized with this Jira Task

bdekoz commented 5 years ago

note, the following ways to get at 'ye old school telemetry GV' on the same device during the same time:

1) about:telemetry
2) adb shell 'run-as ' "$mozpackage" ' cat gv_measurements.json' > gv_local_measurements.json
3) privileged JS running and dumping histograms and scalars with getHistogram/getScalar, etc
bdekoz commented 5 years ago

agh, sorry for the noise. It turns out that I was building debug, and debug has telemetry turned off by default. If I change app/build.gradle to enable telemetry, I see the expected pings in logcat. Phew! Sanity check done.