**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```
Bug 1691631 Comment 0 Edit History
Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.
**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```