1304696 - Intermittent test_safe_browsing_initial_download.py TestSafeBrowsingInitialDownload.test_safe_browsing_initial_download | TimeoutException: Timed out after 28.3 seconds with message: Safe Browsing File: ^goog-unwanted-shavar.pset$ not found!

Status: RESOLVED WORKSFORME

(Testing :: Firefox UI Tests, defect)

Description

[Treeherder Bug Filer]

Filed by: hskupin [at] gmail.com

https://treeherder.mozilla.org/logviewer.html#?job_id=3872875&repo=autoland

https://queue.taskcluster.net/v1/task/HiEicNWZTm-p2oYpJrOvrg/runs/0/artifacts/public%2Flogs%2Flive_backing.log

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Here the downloaded safebrowsing files:

[task 2016-09-22T09:52:22.659404Z] 09:52:22     INFO - Downloaded safebrowsing files: ['goog-malware-shavar.sbstore', 'test-malware-simple.pset', 'mozstd-trackwhite-digest256.pset', 'mozstd-trackwhite-digest256.sbstore', 'test-trackwhite-simple.sbstore', 'test-unwanted-simple.pset', 'goog-malware-shavar.pset', 'goog-phish-shavar.sbstore', 'test-trackwhite-simple.pset', 'test-phish-simple.sbstore', 'test-malware-simple.sbstore', 'test-track-simple.pset', 'test-phish-simple.pset', 'test-block-simple.pset', 'test-track-simple.sbstore', 'base-track-digest256.pset', 'test-unwanted-simple.sbstore', 'goog-badbinurl-shavar.sbstore', 'test-block-simple.sbstore', 'base-track-digest256.sbstore', 'goog-badbinurl-shavar.pset', 'goog-phish-shavar.pset']

Our regular expression for ^goog-unwanted-shavar.pset$ doesn't match for any of those. Francois, maybe we do not always get this file? Or could we really have a long delay until it has been downloaded?

Comment 2

[François Marier [:francois]]

(In reply to Henrik Skupin (:whimboo) from comment #1)
> Our regular expression for ^goog-unwanted-shavar.pset$ doesn't match for any
> of those. Francois, maybe we do not always get this file? Or could we really
> have a long delay until it has been downloaded?

We always request the "unwanted" list, so it should always be present once the list update has finished.

I have not seen this failure before. It is possible that it needs a little bit more time to complete?

Comment 3

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Is there an event or observer notification for when the list update has been finished? Maybe its something we can listen for? I think it would be better to wait until all files have been downloaded and then do the checks. Given that all are downloaded in a random order it could still be that it gets downloaded as very last, and we fail after 30s.

Comment 4

[François Marier [:francois]]

(In reply to Henrik Skupin (:whimboo) from comment #3)
> Is there an event or observer notification for when the list update has been
> finished? Maybe its something we can listen for?

Dimi, you've done a bunch of work on tests that force updates recently. Do you know if there is anything that Henrik could use in the ui-tests?

Comment 5

[Dimi Lee [:dimi]]

Is it possible for ui-tests to check preference - "browser.safebrowsing.provider." + provider + ".lastupdatetime" is updated ?

For example , before update the value might be 1000, then a successful update will change that value.

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+1]]

(In reply to Dimi Lee[:dimi][:dlee] from comment #5)
> Is it possible for ui-tests to check preference -
> "browser.safebrowsing.provider." + provider + ".lastupdatetime" is updated ?
> 
> For example , before update the value might be 1000, then a successful
> update will change that value.

I think that should be possible, even I would have some more questions before I can propose a solution for that. Given that this bug is a specific test failure and we have lots of others similar, lets get the discussion moved to a new bug. It can also better block all other failure bugs.

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Francois, I assume we got this bug fixed at some point? Can you remember?

Comment 8

[François Marier [:francois]]

(In reply to Henrik Skupin (:whimboo) from comment #7)
> Francois, I assume we got this bug fixed at some point? Can you remember?

I would assume so too. Not sure exactly what fixed it, but I suspect increasing the various timeouts in the test and the code probably helped.

Comment 9

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Ok, so lets close as WFM.