Closed
Bug 1691631
Opened 5 years ago
Closed 5 years ago
Intermittent browser/components/protections/test/browser/browser_protections_telemetry.js | Uncaught exception - recorded telemetry for showing the report contains default 'direct' entrypoint - timed out after 50 tries.
Categories
(Firefox :: Protections UI, defect, P5)
Firefox
Protections UI
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=329303029&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Y6dOymrpSbKcrnMbXSZoyg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Y6dOymrpSbKcrnMbXSZoyg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
INFO - TEST-START | browser/components/protections/test/browser/browser_protections_telemetry.js
[task 2021-02-09T02:31:19.242Z] 02:31:19 INFO - GECKO(19575) | 1612837879238 FirefoxAccounts ERROR FxA rejecting with error NO_ACCOUNT, details: undefined
[task 2021-02-09T02:31:19.485Z] 02:31:19 INFO - GECKO(19575) | 1612837879480 FirefoxAccounts ERROR FxA rejecting with error NO_ACCOUNT, details: undefined
[task 2021-02-09T02:31:19.969Z] 02:31:19 INFO - GECKO(19575) | 1612837879957 FirefoxAccounts ERROR FxA rejecting with error NO_ACCOUNT, details: undefined
[task 2021-02-09T02:31:20.452Z] 02:31:20 INFO - GECKO(19575) | 1612837880446 FirefoxAccounts ERROR FxA rejecting with error NO_ACCOUNT, details: undefined
[task 2021-02-09T02:31:33.148Z] 02:31:33 INFO - TEST-INFO | started process screentopng
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - TEST-INFO | screentopng: exit 0
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Buffered messages logged at 02:31:14
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Entering test bound setup
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Leaving test bound setup
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Entering test bound checkTelemetryLoadEvents
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Buffered messages logged at 02:31:16
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for showing the report -
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for closing the report -
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Leaving test bound checkTelemetryLoadEvents
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Entering test bound checkTelemetryClickEvents
[task 2021-02-09T02:31:33.404Z] 02:31:33 INFO - Buffered messages logged at 02:31:19
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO - Console message: [JavaScript Error: "There was an error fetching the user's token: " {file: "resource:///actors/AboutProtectionsParent.jsm" line: 284}]
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO - getMonitorScopedOAuthToken@resource:///actors/AboutProtectionsParent.jsm:284:10
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO -
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO - Console message: [JavaScript Error: "There was an error fetching the user's token: " {file: "resource:///actors/AboutProtectionsParent.jsm" line: 284}]
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO - getMonitorScopedOAuthToken@resource:///actors/AboutProtectionsParent.jsm:284:10
[task 2021-02-09T02:31:33.406Z] 02:31:33 INFO -
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO - Console message: [JavaScript Error: "Unknown Collection "main/fxmonitor-breaches"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 160}]
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:160:5
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:470:13
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO -
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO - waiting for telemetry event count of 4
[task 2021-02-09T02:31:33.408Z] 02:31:33 INFO - got 4 events
[task 2021-02-09T02:31:33.409Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for lw_open_button when there are no breached passwords -
[task 2021-02-09T02:31:33.409Z] 02:31:33 INFO - Console message: [JavaScript Error: "There was an error fetching the user's token: " {file: "resource:///actors/AboutProtectionsParent.jsm" line: 284}]
[task 2021-02-09T02:31:33.409Z] 02:31:33 INFO - getMonitorScopedOAuthToken@resource:///actors/AboutProtectionsParent.jsm:284:10
[task 2021-02-09T02:31:33.409Z] 02:31:33 INFO -
[task 2021-02-09T02:31:33.410Z] 02:31:33 INFO - Buffered messages logged at 02:31:20
[task 2021-02-09T02:31:33.413Z] 02:31:33 INFO - waiting for telemetry event count of 7
[task 2021-02-09T02:31:33.413Z] 02:31:33 INFO - got 7 events
[task 2021-02-09T02:31:33.413Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for lw_open_button when there are breached passwords -
[task 2021-02-09T02:31:33.413Z] 02:31:33 INFO - Console message: [JavaScript Error: "There was an error fetching the user's token: " {file: "resource:///actors/AboutProtectionsParent.jsm" line: 284}]
[task 2021-02-09T02:31:33.414Z] 02:31:33 INFO - getMonitorScopedOAuthToken@resource:///actors/AboutProtectionsParent.jsm:284:10
[task 2021-02-09T02:31:33.414Z] 02:31:33 INFO -
[task 2021-02-09T02:31:33.414Z] 02:31:33 INFO - waiting for telemetry event count of 10
[task 2021-02-09T02:31:33.414Z] 02:31:33 INFO - got 10 events
[task 2021-02-09T02:31:33.415Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for lw_open_button when there are no stored passwords -
[task 2021-02-09T02:31:33.415Z] 02:31:33 INFO - waiting for telemetry event count of 11
[task 2021-02-09T02:31:33.415Z] 02:31:33 INFO - got 11 events
[task 2021-02-09T02:31:33.415Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for lw_about_link -
[task 2021-02-09T02:31:33.416Z] 02:31:33 INFO - Buffered messages logged at 02:31:21
[task 2021-02-09T02:31:33.416Z] 02:31:33 INFO - waiting for telemetry event count of 12
[task 2021-02-09T02:31:33.416Z] 02:31:33 INFO - got 12 events
[task 2021-02-09T02:31:33.418Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for mtr_about_link -
[task 2021-02-09T02:31:33.418Z] 02:31:33 INFO - waiting for telemetry event count of 13
[task 2021-02-09T02:31:33.419Z] 02:31:33 INFO - got 13 events
[task 2021-02-09T02:31:33.421Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for mtr_signup_button -
[task 2021-02-09T02:31:33.421Z] 02:31:33 INFO - waiting for telemetry event count of 14
[task 2021-02-09T02:31:33.422Z] 02:31:33 INFO - got 14 events
[task 2021-02-09T02:31:33.422Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for social trackers_about_link -
[task 2021-02-09T02:31:33.423Z] 02:31:33 INFO - waiting for telemetry event count of 15
[task 2021-02-09T02:31:33.423Z] 02:31:33 INFO - got 15 events
[task 2021-02-09T02:31:33.423Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for cookie trackers_about_link -
[task 2021-02-09T02:31:33.424Z] 02:31:33 INFO - waiting for telemetry event count of 16
[task 2021-02-09T02:31:33.424Z] 02:31:33 INFO - got 16 events
[task 2021-02-09T02:31:33.426Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for content tracker trackers_about_link -
[task 2021-02-09T02:31:33.426Z] 02:31:33 INFO - Buffered messages logged at 02:31:22
[task 2021-02-09T02:31:33.426Z] 02:31:33 INFO - waiting for telemetry event count of 17
[task 2021-02-09T02:31:33.427Z] 02:31:33 INFO - got 17 events
[task 2021-02-09T02:31:33.427Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for fingerprinter trackers_about_link -
[task 2021-02-09T02:31:33.427Z] 02:31:33 INFO - waiting for telemetry event count of 18
[task 2021-02-09T02:31:33.428Z] 02:31:33 INFO - got 18 events
[task 2021-02-09T02:31:33.428Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for cryptominer trackers_about_link -
[task 2021-02-09T02:31:33.429Z] 02:31:33 INFO - waiting for telemetry event count of 19
[task 2021-02-09T02:31:33.430Z] 02:31:33 INFO - got 19 events
[task 2021-02-09T02:31:33.430Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for settings_link header-settings -
[task 2021-02-09T02:31:33.431Z] 02:31:33 INFO - waiting for telemetry event count of 20
[task 2021-02-09T02:31:33.431Z] 02:31:33 INFO - got 20 events
[task 2021-02-09T02:31:33.432Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for settings_link custom-card-settings -
[task 2021-02-09T02:31:33.432Z] 02:31:33 INFO - Buffered messages logged at 02:31:23
[task 2021-02-09T02:31:33.432Z] 02:31:33 INFO - waiting for telemetry event count of 23
[task 2021-02-09T02:31:33.434Z] 02:31:33 INFO - got 23 events
[task 2021-02-09T02:31:33.435Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for resolve breaches button -
[task 2021-02-09T02:31:33.435Z] 02:31:33 INFO - waiting for telemetry event count of 24
[task 2021-02-09T02:31:33.435Z] 02:31:33 INFO - got 24 events
[task 2021-02-09T02:31:33.436Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for monitor known breaches block -
[task 2021-02-09T02:31:33.436Z] 02:31:33 INFO - waiting for telemetry event count of 25
[task 2021-02-09T02:31:33.436Z] 02:31:33 INFO - got 25 events
[task 2021-02-09T02:31:33.437Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for monitor exposed passwords block -
[task 2021-02-09T02:31:33.437Z] 02:31:33 INFO - Buffered messages logged at 02:31:24
[task 2021-02-09T02:31:33.437Z] 02:31:33 INFO - waiting for telemetry event count of 28
[task 2021-02-09T02:31:33.439Z] 02:31:33 INFO - got 28 events
[task 2021-02-09T02:31:33.439Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for manage breaches button -
[task 2021-02-09T02:31:33.440Z] 02:31:33 INFO - waiting for telemetry event count of 31
[task 2021-02-09T02:31:33.440Z] 02:31:33 INFO - got 31 events
[task 2021-02-09T02:31:33.441Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for view report button -
[task 2021-02-09T02:31:33.441Z] 02:31:33 INFO - waiting for telemetry event count of 34
[task 2021-02-09T02:31:33.441Z] 02:31:33 INFO - got 34 events
[task 2021-02-09T02:31:33.442Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for view report button -
[task 2021-02-09T02:31:33.442Z] 02:31:33 INFO - Buffered messages logged at 02:31:25
[task 2021-02-09T02:31:33.442Z] 02:31:33 INFO - waiting for telemetry event count of 35
[task 2021-02-09T02:31:33.443Z] 02:31:33 INFO - got 35 events
[task 2021-02-09T02:31:33.444Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for monitor email block -
[task 2021-02-09T02:31:33.445Z] 02:31:33 INFO - waiting for telemetry event count of 36
[task 2021-02-09T02:31:33.445Z] 02:31:33 INFO - got 36 events
[task 2021-02-09T02:31:33.445Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for monitor known breaches block -
[task 2021-02-09T02:31:33.446Z] 02:31:33 INFO - waiting for telemetry event count of 37
[task 2021-02-09T02:31:33.446Z] 02:31:33 INFO - got 37 events
[task 2021-02-09T02:31:33.446Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | recorded telemetry for monitor exposed passwords block -
[task 2021-02-09T02:31:33.446Z] 02:31:33 INFO - Leaving test bound checkTelemetryClickEvents
[task 2021-02-09T02:31:33.448Z] 02:31:33 INFO - Entering test bound test_save_telemetry
[task 2021-02-09T02:31:33.448Z] 02:31:33 INFO - TEST-PASS | browser/components/protections/test/browser/browser_protections_telemetry.js | undefined assertion name -
[task 2021-02-09T02:31:33.449Z] 02:31:33 INFO - Leaving test bound test_save_telemetry
[task 2021-02-09T02:31:33.449Z] 02:31:33 INFO - Entering test bound checkTelemetryLoadEventForEntrypoint
[task 2021-02-09T02:31:33.450Z] 02:31:33 INFO - Buffered messages logged at 02:31:27
[task 2021-02-09T02:31:33.450Z] 02:31:33 INFO - Typo in 'entrypoint' should not be recorded
[task 2021-02-09T02:31:33.451Z] 02:31:33 INFO - Buffered messages finished
[task 2021-02-09T02:31:33.452Z] 02:31:33 INFO - TEST-UNEXPECTED-FAIL | browser/components/protections/test/browser/browser_protections_telemetry.js | Uncaught exception - recorded telemetry for showing the report contains default 'direct' entrypoint - timed out after 50 tries.
[task 2021-02-09T02:31:33.452Z] 02:31:33 INFO - Leaving test bound checkTelemetryLoadEventForEntrypoint
[task 2021-02-09T02:31:33.453Z] 02:31:33 INFO - TEST-SKIP | browser/components/protections/test/browser/browser_protections_telemetry.js | bound checkTelemetryClickEventsVPN
[task 2021-02-09T02:31:33.453Z] 02:31:33 WARNING - Skipping test bound checkTelemetryClickEventsVPN
[task 2021-02-09T02:31:33.454Z] 02:31:33 INFO - TEST-SKIP | browser/components/protections/test/browser/browser_protections_telemetry.js | bound checkTelemetryEventsVPNBanner
[task 2021-02-09T02:31:33.454Z] 02:31:33 WARNING - Skipping test bound checkTelemetryEventsVPNBanner
[task 2021-02-09T02:31:33.455Z] 02:31:33 INFO - GECKO(19575) | MEMORY STAT | vsize 2966MB | residentFast 301MB | heapAllocated 90MB
[task 2021-02-09T02:31:33.455Z] 02:31:33 INFO - TEST-OK | browser/components/protections/test/browser/browser_protections_telemetry.js | took 18908ms
[task 2021-02-09T02:31:33.456Z] 02:31:33 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-09T02:31:33.456Z] 02:31:33 INFO - TEST-UNEXPECTED-FAIL | browser/components/protections/test/browser/browser_protections_telemetry.js | Found an unexpected tab at the end of test run: about:protections?entryPoint=newPage -
[task 2021-02-09T02:31:33.456Z] 02:31:33 INFO - checking window state
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - GECKO(19575) | Completed ShutdownLeaks collections in process 19575
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - TEST-START | Shutdown
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - Browser Chrome Test Summary
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - Passed: 52
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - Failed: 2
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - Todo: 0
[task 2021-02-09T02:31:33.457Z] 02:31:33 INFO - Mode: e10s
[task 2021-02-09T02:31:33.461Z] 02:31:33 INFO - *** End BrowserChrome Test Results ***
[task 2021-02-09T02:31:33.461Z] 02:31:33 INFO - GECKO(19575) | Exiting due to channel error.
[task 2021-02-09T02:31:33.462Z] 02:31:33 INFO - GECKO(19575) | Exiting due to channel error.
[task 2021-02-09T02:31:33.463Z] 02:31:33 INFO - GECKO(19575) | Exiting due to channel error.
[task 2021-02-09T02:31:33.463Z] 02:31:33 INFO - GECKO(19575) | Exiting due to channel error.
[task 2021-02-09T02:31:33.464Z] 02:31:33 INFO - GECKO(19575) | Exiting due to channel error.
[task 2021-02-09T02:31:33.464Z] 02:31:33 INFO - TEST-INFO | Main app process: exit 0
[task 2021-02-09T02:31:33.465Z] 02:31:33 INFO - runtests.py | Application ran for: 0:00:37.657617
[task 2021-02-09T02:31:33.466Z] 02:31:33 INFO - zombiecheck | Reading PID log: /tmp/tmpQASPFSpidlog
[task 2021-02-09T02:31:33.466Z] 02:31:33 INFO - ==> process 19575 launched child process 19597
[task 2021-02-09T02:31:33.467Z] 02:31:33 INFO - ==> process 19575 launched child process 19632
[task 2021-02-09T02:31:33.467Z] 02:31:33 INFO - ==> process 19575 launched child process 19641
[task 2021-02-09T02:31:33.468Z] 02:31:33 INFO - ==> process 19575 launched child process 19739
[task 2021-02-09T02:31:33.468Z] 02:31:33 INFO - ==> process 19575 launched child process 19770
[task 2021-02-09T02:31:33.468Z] 02:31:33 INFO - ==> process 19575 launched child process 19804
[task 2021-02-09T02:31:33.469Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19597
[task 2021-02-09T02:31:33.469Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19632
[task 2021-02-09T02:31:33.469Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19641
[task 2021-02-09T02:31:33.470Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19770
[task 2021-02-09T02:31:33.470Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19739
[task 2021-02-09T02:31:33.470Z] 02:31:33 INFO - zombiecheck | Checking for orphan process with PID: 19804
[task 2021-02-09T02:31:33.471Z] 02:31:33 INFO - Stopping web server
[task 2021-02-09T02:31:33.472Z] 02:31:33 INFO - Stopping web socket server
[task 2021-02-09T02:31:33.507Z] 02:31:33 INFO - Stopping ssltunnel
[task 2021-02-09T02:31:33.528Z] 02:31:33 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2021-02-09T02:31:33.528Z] 02:31:33 INFO - runtests.py | Running tests: end.
[task 2021-02-09T02:31:33.550Z] 02:31:33 INFO - Buffered messages finished
[task 2021-02-09T02:31:33.551Z] 02:31:33 INFO - TEST-INFO | checking window state
[task 2021-02-09T02:31:33.551Z] 02:31:33 INFO - Browser Chrome Test Summary
[task 2021-02-09T02:31:33.552Z] 02:31:33 INFO - Passed: 52
[task 2021-02-09T02:31:33.552Z] 02:31:33 INFO - Failed: 2
[task 2021-02-09T02:31:33.553Z] 02:31:33 INFO - Todo: 0
[task 2021-02-09T02:31:33.554Z] 02:31:33 INFO - Mode: e10s
[task 2021-02-09T02:31:33.554Z] 02:31:33 INFO - *** End BrowserChrome Test Results ***
[task 2021-02-09T02:31:33.555Z] 02:31:33 INFO - Buffered messages finished
[task 2021-02-09T02:31:33.555Z] 02:31:33 INFO - SUITE-END | took 38s
[task 2021-02-09T02:31:33.556Z] 02:31:33 INFO - SUITE-START | Running 1 tests```
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•