1338638 - Intermittent test_safe_browsing_initial_download.py TestSafeBrowsingInitialDownload.test_safe_browsing_initial_download | AssertionError: 'mozplugin-block-digest256.sbstore' not found in ['test-phish-simple.sbstore', 'test-unwanted-simple.sbstore',

Status: RESOLVED FIXED

(Toolkit :: Safe Browsing, defect, P1)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de

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

https://queue.taskcluster.net/v1/task/BQZO4nYbQvuKHViKCO7V6Q/runs/0/artifacts/public/logs/live_backing.log

Comment 1

[Intermittent Failures Robot]

12 failures in 833 pushes (0.014 failures/push) were associated with this bug in the last 7 days.  
Repository breakdown:
* mozilla-inbound: 5
* autoland: 5
* try: 1
* mozilla-aurora: 1

Platform breakdown:
* linux64: 8
* linux32: 4

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-02-13&endday=2017-02-19&tree=all

Comment 2

[Intermittent Failures Robot]

6 failures in 783 pushes (0.008 failures/push) were associated with this bug in the last 7 days.  
Repository breakdown:
* mozilla-central: 4
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* linux64: 3
* linux32: 3

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-02-27&endday=2017-03-05&tree=all

Comment 3

[Intermittent Failures Robot]

5 failures in 777 pushes (0.006 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* try: 2
* mozilla-inbound: 2
* autoland: 1

Platform breakdown:
* linux64: 4
* windowsxp: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-03-13&endday=2017-03-19&tree=all

Comment 4

[Intermittent Failures Robot]

19 failures in 898 pushes (0.021 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 13
* mozilla-inbound: 2
* mozilla-beta: 2
* try: 1
* graphics: 1

Platform breakdown:
* linux64: 13
* linux32: 4
* linux64-nightly: 1
* linux32-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-03-20&endday=2017-03-26&tree=all

Comment 5

[Intermittent Failures Robot]

8 failures in 845 pushes (0.009 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-central: 3
* autoland: 2
* mozilla-inbound: 1
* mozilla-beta: 1
* graphics: 1

Platform breakdown:
* linux64: 6
* windows7-64: 1
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-03-27&endday=2017-04-02&tree=all

Comment 6

[Intermittent Failures Robot]

26 failures in 185 pushes (0.141 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 11
* mozilla-inbound: 7
* pine: 3
* mozilla-central: 3
* try: 1
* graphics: 1

Platform breakdown:
* linux64: 21
* linux32: 5

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-07&endday=2017-04-07&tree=all

Comment 7

[Intermittent Failures Robot]

73 failures in 867 pushes (0.084 failures/push) were associated with this bug in the last 7 days. 

This is the #21 most frequent failure this week.  

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. ** 

Repository breakdown:
* autoland: 28
* mozilla-inbound: 25
* try: 10
* mozilla-central: 6
* pine: 3
* graphics: 1

Platform breakdown:
* linux64: 50
* linux32: 22
* linux64-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-03&endday=2017-04-09&tree=all

Comment 8

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

Francois, can you please have a look? Something seems to be wrong here.

Comment 9

[Geoff Brown [:gbrown]]

Started with https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=baaee2deb3acc98c0eb0e5f14b13b20e346788ff&filter-searchStr=en-US.

Comment 10

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

Thank you Geoff for checking. Henry, can you please have a look? Thanks.

Comment 11

[Intermittent Failures Robot]

46 failures in 150 pushes (0.307 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 21
* mozilla-inbound: 11
* graphics: 7
* mozilla-central: 6
* try: 1

Platform breakdown:
* linux64: 33
* linux32: 11
* osx-10-10: 1
* android-6-0-armv8-api15: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-10&endday=2017-04-10&tree=all

Comment 12

[Henry Chang [:hchang]]

Spun up a try with logs to see what's happening.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=229f75fbca4b8cd59bcd3e3814726e95f8961316

Comment 13

[Henry Chang [:hchang]]

Attachment: Bug 1338638 - Fix race condition for DBService APIs to avoid long delayed initial download.

When starting up, SafeBrowsing.jsm will try to use DBService to add testing entries. Meanwhile,
listmanager will request StreamUpdater to download lists with a random initial delay.

The requests that listmanager issue to StreamUpdater will be queued up
if DBserve is busy and will be retried when StreamUpdater is notified that
the previous update is complete. However, in some edge cases,
the queued requests may not be processed until the next update request from listmanager.
For example, SafeBrowsing.jsm calls DBService.beginUpdate at t0 and the update is
complete at t1. If listmanager sends all requests via StreamUpdate between t0 and t1,
they will all be queued up and no further request can trigger the queued ones.

So in this patch I add a timer to re-trigger FetchNextRequest() in case StreamUpdater is not
notified the previous update is complete.

Review commit: https://reviewboard.mozilla.org/r/128820/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/128820/

Comment 14

[François Marier [:francois]]

Comment on attachment 8856898 [details]
Bug 1338638 - Fix race condition for DBService APIs to avoid long delayed initial download.

https://reviewboard.mozilla.org/r/128820/#review131530

That solution looks great. I only have a few nits.

::: toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.h:87
(Diff revision 1)
>    nsCOMPtr<nsIUrlClassifierDBService> mDBService;
> -  nsCOMPtr<nsITimer> mTimer;
>  
> +  // In v2, a update response might contain redirection and this
> +  // timer is for fetching the redirected update.
> +  nsCOMPtr<nsITimer> mFetchNextUpdateTimer;

The naming is a little confusing now that we have two timers.

How about `mFetchIndirectUpdatesTimer` for this one?

::: toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.cpp:290
(Diff revision 1)
>      request->mUrl = aUpdateUrl;
>      request->mSuccessCallback = aSuccessCallback;
>      request->mUpdateErrorCallback = aUpdateErrorCallback;
>      request->mDownloadErrorCallback = aDownloadErrorCallback;
> +
> +    // We cannot guarantee DBService is busy on processing request

Based on your commit message, I would suggest this explanation:

"We cannot guarantee that we will be notified when DBService is done processing the current update, so we fire a retry timer on our own."

::: toolkit/components/url-classifier/nsUrlClassifierStreamUpdater.cpp:878
(Diff revision 1)
> -  // Start the update process up again.
> +    // Start the update process up again.
> -  FetchNext();
> +    FetchNext();
> +    return NS_OK;
> +  }
>  
> +  NS_WARNING("A timer is fired from nowhere.");

Maybe that should be an assert instead so that it fails on debug builds in try?

Comment 15

[Intermittent Failures Robot]

42 failures in 153 pushes (0.275 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 13
* mozilla-inbound: 11
* graphics: 10
* mozilla-central: 4
* try: 3
* pine: 1

Platform breakdown:
* linux64: 31
* linux32: 9
* osx-10-10: 1
* linux64-ccov: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-11&endday=2017-04-11&tree=all

Comment 16

[Henry Chang [:hchang]]

Comment on attachment 8856898 [details]
Bug 1338638 - Fix race condition for DBService APIs to avoid long delayed initial download.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/128820/diff/1-2/

Comment 17

[Henry Chang [:hchang]]

Comment on attachment 8856898 [details]
Bug 1338638 - Fix race condition for DBService APIs to avoid long delayed initial download.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/128820/diff/2-3/

Comment 18

[François Marier [:francois]]

Comment on attachment 8856898 [details]
Bug 1338638 - Fix race condition for DBService APIs to avoid long delayed initial download.

https://reviewboard.mozilla.org/r/128820/#review132174

Comment 19

[Intermittent Failures Robot]

62 failures in 154 pushes (0.403 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* autoland: 33
* mozilla-inbound: 11
* mozilla-central: 9
* graphics: 8
* try: 1

Platform breakdown:
* linux64: 43
* linux32: 15
* osx-10-9: 1
* osx-10-10: 1
* linux64-stylo: 1
* linux32-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-12&endday=2017-04-12&tree=all

Comment 20

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/17180b888f7c
Fix race condition for DBService APIs to avoid long delayed initial download. r=francois

Comment 21

[Intermittent Failures Robot]

88 failures in 205 pushes (0.429 failures/push) were associated with this bug yesterday.   

Repository breakdown:
* mozilla-inbound: 39
* autoland: 28
* mozilla-central: 11
* graphics: 7
* try: 3

Platform breakdown:
* linux64: 61
* linux32: 26
* linux32-nightly: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-13&endday=2017-04-13&tree=all

Comment 22

[Iris Hsiao [:ihsiao]]

https://hg.mozilla.org/mozilla-central/rev/17180b888f7c

Comment 23

[Intermittent Failures Robot]

264 failures in 894 pushes (0.295 failures/push) were associated with this bug in the last 7 days. 

This is the #5 most frequent failure this week. 

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **  

Repository breakdown:
* autoland: 97
* mozilla-inbound: 80
* mozilla-central: 33
* graphics: 33
* try: 18
* oak: 2
* pine: 1

Platform breakdown:
* linux64: 190
* linux32: 65
* osx-10-10: 3
* linux32-nightly: 2
* osx-10-9: 1
* linux64-stylo: 1
* linux64-ccov: 1
* android-6-0-armv8-api15: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-04-10&endday=2017-04-16&tree=all

Comment 24

[Ryan VanderMeulen [:RyanVM]]

These failures affect 54 too. Should we consider uplifting?

Comment 25

[Henry Chang [:hchang]]

The fix is fairly simple so uplifting around should be safe. I'll do it. Thanks!

Comment 26

[Henry Chang [:hchang]]

Oops. After checking the 54 code base, the root cause of this issue (Bug 1339050) is not there.

Ryan, could you suggest how you conclude that? I checked 

https://treeherder.mozilla.org/#/jobs?repo=mozilla-aurora

and didn't see relevant failures :(

Comment 27

[Ryan VanderMeulen [:RyanVM]]

54 is on Beta now, for one thing :). Maybe the failures are similar but different then?

https://treeherder.mozilla.org/logviewer.html#?job_id=93849205&repo=mozilla-beta

Comment 28

[Henry Chang [:hchang]]

As far as I can tell, that's a similar failure and we do have one intermittent bug
for that test case. So the failure you indicated is only appeared in beta but not 
in aurora?

Comment 29

[Ryan VanderMeulen [:RyanVM]]

Aurora doesn't exist anymore.

Comment 30

[Gerry Chang [:gchang]]

After discussing with Henry, the root cause of this intermittent error in 54 is different from 55 Nightly. Given the root cause is different, mark 54 won't fix.

Comment 31

[Intermittent Failures Robot]

1 failures in 824 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-esr52: 1

Platform breakdown:
* linux64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1338638&startday=2017-10-02&endday=2017-10-08&tree=all