Closed Bug 1596596 Opened 6 years ago Closed 6 years ago

Intermittent testing/firefox-ui/tests/functional/safebrowsing/test_initial_download.py TestSafeBrowsingInitialDownload.test_safe_browsing_initial_download | AssertionError: 'ads-track-digest256.sbstore' not found in [u'google4']

Categories

(Toolkit :: Safe Browsing, defect, P5)

Product:
Toolkit
Component:
Safe Browsing
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=276304594&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/SlyQIovQT0CtCG05ZVAK7g/runs/0/artifacts/public/logs/live_backing.log

[task 2019-11-14T22:55:51.092Z] 22:55:51 INFO - TEST-START | testing/firefox-ui/tests/functional/safebrowsing/test_initial_download.py TestSafeBrowsingInitialDownload.test_safe_browsing_initial_download
[task 2019-11-14T22:58:44.526Z] 22:58:44 INFO - 1573772324522 Marionette DEBUG 1 -> [0,9657,"WebDriver:GetPageSource",{}]
[task 2019-11-14T22:58:44.528Z] 22:58:44 INFO - 1573772324525 Marionette DEBUG 1 <- [1,9657,null,{"value":"<html><head></head><body></body></html>"}]
[task 2019-11-14T22:58:44.583Z] 22:58:44 INFO - TEST-UNEXPECTED-FAIL | testing/firefox-ui/tests/functional/safebrowsing/test_initial_download.py TestSafeBrowsingInitialDownload.test_safe_browsing_initial_download | AssertionError: 'ads-track-digest256.sbstore' not found in [u'google4']
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - Traceback (most recent call last):
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - File "/Users/cltbld/tasks/task_1573772064/build/venv/lib/python2.7/site-packages/marionette_harness/marionette_test/testcases.py", line 159, in run
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - testMethod()
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - File "/Users/cltbld/tasks/task_1573772064/build/tests/firefox-ui/tests/testing/firefox-ui/tests/functional/safebrowsing/test_initial_download.py", line 111, in test_safe_browsing_initial_download
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - self.assertIn(f, files_on_disk_toplevel)
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - TEST-INFO took 173435ms
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - 1573772324526 Marionette DEBUG 1 -> [0,9658,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - 1573772324526 Marionette DEBUG 1 <- [1,9658,null,{"value":null}]
[task 2019-11-14T22:58:44.584Z] 22:58:44 INFO - 1573772324528 Marionette DEBUG 1 -> [0,9659,"Marionette:GetContext",{}]
[task 2019-11-14T22:58:44.585Z] 22:58:44 INFO - 1573772324528 Marionette DEBUG 1 <- [1,9659,null,{"value":"chrome"}]
[task 2019-11-14T22:58:44.585Z] 22:58:44 INFO - 1573772324529 Marionette DEBUG 1 -> [0,9660,"WebDriver:DeleteSession",{}]
[task 2019-11-14T22:58:44.585Z] 22:58:44 INFO - 1573772324530 Marionette DEBUG 1 <- [1,9660,null,{"value":null}]
[task 2019-11-14T22:58:44.619Z] 22:58:44 INFO - Application command: /Users/cltbld/tasks/task_1573772064/build/application/Firefox Nightly.app/Contents/MacOS/firefox -no-remote -marionette -foreground -profile /Users/cltbld/tasks/task_1573772064/build/tmpAJKgZf.mozrunner
[task 2019-11-14T22:58:45.354Z] 22:58:45 INFO - 1573772325342 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
[task 2019-11-14T22:58:45.362Z] 22:58:45 INFO - 1573772325343 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
[task 2019-11-14T22:58:45.362Z] 22:58:45 INFO - 1573772325343 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
[task 2019-11-14T22:58:45.362Z] 22:58:45 INFO - 1573772325343 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[task 2019-11-14T22:58:45.467Z] 22:58:45 INFO - 1573772325452 Marionette TRACE Received observer notification profile-after-change
[task 2019-11-14T22:58:45.610Z] 22:58:45 INFO - 1573772325586 Marionette TRACE Received observer notification command-line-startup
[task 2019-11-14T22:58:45.837Z] 22:58:45 INFO - 1573772325811 Marionette TRACE Received observer notification toplevel-window-ready
[task 2019-11-14T22:58:47.528Z] 22:58:47 INFO - 1573772327484 Marionette TRACE Received observer notification marionette-startup-requested
[task 2019-11-14T22:58:47.528Z] 22:58:47 INFO - 1573772327484 Marionette TRACE Waiting until startup recorder finished recording startup scripts...
[task 2019-11-14T22:58:47.529Z] 22:58:47 INFO - 1573772327506 Marionette TRACE All scripts recorded.
[task 2019-11-14T22:58:47.599Z] 22:58:47 INFO - 1573772327545 Marionette INFO Listening on port 2828
[task 2019-11-14T22:58:47.599Z] 22:58:47 INFO - 1573772327545 Marionette DEBUG Remote service is active
[task 2019-11-14T22:58:47.633Z] 22:58:47 INFO - 1573772327601 Marionette DEBUG Accepted connection 0 from 127.0.0.1:50257
[task 2019-11-14T22:58:47.633Z] 22:58:47 INFO - 1573772327603 Marionette DEBUG Accepted connection 1 from 127.0.0.1:50258
[task 2019-11-14T22:58:47.633Z] 22:58:47 INFO - 1573772327604 Marionette DEBUG Closed connection 0
[task 2019-11-14T22:58:47.633Z] 22:58:47 INFO - 1573772327608 Marionette DEBUG 1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2019-11-14T22:58:47.635Z] 22:58:47 INFO - 1573772327629 Marionette TRACE [17] Frame script loaded
[task 2019-11-14T22:58:47.652Z] 22:58:47 INFO - 1573772327636 Marionette TRACE [17] Frame script registered
[task 2019-11-14T22:58:47.672Z] 22:58:47 INFO - 1573772327642 Marionette DEBUG 1 <- [1,1,null,{"sessionId":"b4484ef8-0a35-2149-bddb-66dd53741a53","capabilities":{"browserName":"firefox","browserVersion":"72.0a ... ld/tmpAJKgZf.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
[task 2019-11-14T22:58:47.672Z] 22:58:47 INFO - 1573772327652 Marionette DEBUG 1 -> [0,2,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-11-14T22:58:47.672Z] 22:58:47 INFO - 1573772327653 Marionette DEBUG 1 <- [1,2,null,{"value":null}]
[task 2019-11-14T22:58:47.672Z] 22:58:47 INFO - 1573772327655 Marionette DEBUG 1 -> [0,3,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-11-14T22:58:47.672Z] 22:58:47 INFO - 1573772327655 Marionette DEBUG 1 <- [1,3,null,["3"]]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327657 Marionette DEBUG 1 -> [0,4,"WebDriver:GetChromeWindowHandle",{}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327658 Marionette DEBUG 1 <- [1,4,null,{"value":"3"}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327663 Marionette DEBUG 1 -> [0,5,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327664 Marionette DEBUG 1 <- [1,5,null,["3"]]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327665 Marionette DEBUG 1 -> [0,6,"WebDriver:SwitchToWindow",{"handle":"3","focus":true,"name":"3"}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327666 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327667 Marionette DEBUG 1 -> [0,7,"WebDriver:GetChromeWindowHandle",{}]
[task 2019-11-14T22:58:47.673Z] 22:58:47 INFO - 1573772327667 Marionette DEBUG 1 <- [1,7,null,{"value":"3"}]
[task 2019-11-14T22:58:47.674Z] 22:58:47 INFO - 1573772327668 Marionette DEBUG 1 -> [0,8,"Marionette:GetContext",{}]
[task 2019-11-14T22:58:47.674Z] 22:58:47 INFO - 1573772327668 Marionette DEBUG 1 <- [1,8,null,{"value":"chrome"}]
[task 2019-11-14T22:58:47.686Z] 22:58:47 INFO - 1573772327670 Marionette DEBUG 1 -> [0,9,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-11-14T22:58:47.686Z] 22:58:47 INFO - 1573772327670 Marionette DEBUG 1 <- [1,9,null,{"value":null}]
[task 2019-11-14T22:58:47.686Z] 22:58:47 INFO - 1573772327672 Marionette DEBUG 1 -> [0,10,"WebDriver:GetChromeWindowHandle",{}]
[task 2019-11-14T22:58:47.687Z] 22:58:47 INFO - 1573772327673 Marionette DEBUG 1 <- [1,10,null,{"value":"3"}]
[task 2019-11-14T22:58:47.687Z] 22:58:47 INFO - 1573772327674 Marionette DEBUG 1 -> [0,11,"Marionette:GetWindowType",{}]
[task 2019-11-14T22:58:47.687Z] 22:58:47 INFO - 1573772327675 Marionette DEBUG 1 <- [1,11,null,{"value":"navigator:browser"}]
[task 2019-11-14T22:58:47.687Z] 22:58:47 INFO - 1573772327676 Marionette DEBUG 1 -> [0,12,"WebDriver:GetChromeWindowHandles",{}]
[task 2019-11-14T22:58:47.688Z] 22:58:47 INFO - 1573772327676 Marionette DEBUG 1 <- [1,12,null,["3"]]
[task 2019-11-14T22:58:47.688Z] 22:58:47 INFO - 1573772327677 Marionette DEBUG 1 -> [0,13,"Marionette:GetContext",{}]
[task 2019-11-14T22:58:47.688Z] 22:58:47 INFO - 1573772327678 Marionette DEBUG 1 <- [1,13,null,{"value":"chrome"}]
[task 2019-11-14T22:58:47.688Z] 22:58:47 INFO - 1573772327678 Marionette DEBUG 1 -> [0,14,"Marionette:SetContext",{"value":"chrome"}]
[task 2019-11-14T22:58:47.689Z] 22:58:47 INFO - 1573772327679 Marionette DEBUG 1 <- [1,14,null,{"value":null}]
[task 2019-11-14T22:58:47.690Z] 22:58:47 INFO - 1573772327680 Marionette DEBUG 1 -> [0,15,"WebDriver:ExecuteScript",{"script":"Components.utils.import("resource://gre/modules/Services.jsm");\n\n ... s":["3"],"filename":"../../venv/lib/python2.7/site-packages/firefox_puppeteer/ui/windows.py","sandbox":"default","line":144}]

From the log:

[task 2019-11-14T22:55:54.243Z] 22:55:54     INFO -   update: https://shavar.services.mozilla.com/downloads?client=navclient-auto-ffox&appver=72.0a&pver=2.2 tablelist: mozplugin-block-digest256,ads-track-digest256,social-track-digest256,analytics-track-digest256,content-track-digest256,mozstd-trackwhite-digest256,allow-flashallow-digest256,except-flashallow-digest256,block-flash-digest256,except-flash-digest256,block-flashsubdoc-digest256,except-flashsubdoc-digest256,base-fingerprinting-track-digest256,base-cryptomining-track-digest256,social-tracking-protection-facebook-digest256,social-tracking-protection-linkedin-digest256,social-tracking-protection-twitter-digest256
..
[task 2019-11-14T22:55:54.332Z] 22:55:54     INFO -  listmanager: 22:55:54 GMT+0000 (Greenwich Mean Time): download error for mozplugin-block-digest256,ads-track-digest256,social-track-digest256,analytics-track-digest256,content-track-digest256,mozstd-trackwhite-digest256,allow-flashallow-digest256,except-flashallow-digest256,block-flash-digest256,except-flash-digest256,block-flashsubdoc-digest256,except-flashsubdoc-digest256,base-fingerprinting-track-digest256,base-cryptomining-track-digest256,social-tracking-protection-facebook-digest256,social-tracking-protection-linkedin-digest256,social-tracking-protection-twitter-digest256: 504

There are download errors again. Dimi can you please have a look?

Component: Firefox UI Tests → Safe Browsing
Flags: needinfo?(dlee)
Product: Testing → Toolkit
QA Contact: hskupin
Version: Version 3 → unspecified

The error is 504 Gateway timeout and there are total only 4 failures, I guess that might be just something wrong in the network when that happened.

Flags: needinfo?(dlee)

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.