1501040 - Perma beta raptor-firefox-tp6 JavaScript error: resource://gre/modules/addons/XPIProvider.jsm, line 2600: TypeError: addon is null; can't access its "seen" property

Status: RESOLVED FIXED

(Testing :: Raptor, defect, P1)

Description

[Treeherder Bug Filer]

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

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

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

In bug 1495310 Talos tp6 got turned off for beta and Raptor Firefox tp6 turned on because Talos tp6 was broken. Raptor tp6 fails on beta due to addon signing issues. The test of Raptor tp6 accidentally used raptor chrome.

If Raptor tp6 gets turned off for tp6, there won't be a tp6 measurement.

09:50:32     INFO -  Application command: /home/cltbld/workspace/build/application/firefox/firefox -profile /tmp/tmpozcCGe.mozrunner
09:50:32     INFO -  PID 29152 | 1540227032333	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
09:50:32     INFO -  PID 29152 | 1540227032333	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
09:50:32     INFO -  PID 29152 | 1540227032333	addons.xpi-utils	WARN	addMetadata: Add-on [e-mail] is invalid: Error: Extension [e-mail] is not correctly signed(resource://gre/modules/addons/XPIDatabase.jsm:2426:17) JS Stack trace: [e-mail]:2426:17
09:50:33    ERROR -  PID 29152 | JavaScript error: resource://gre/modules/addons/XPIProvider.jsm, line 2600: TypeError: addon is null; can't access its "seen" property
10:02:58     INFO -  raptor-main application timed out after 750 seconds
10:03:14     INFO -  raptor-mitmproxy Stopping mitmproxy playback, klling process 29145
10:03:14     INFO -  Replaying from files: ['/home/cltbld/workspace/testing/raptor/amazon.mp']
10:03:24     INFO -  raptor-mitmproxy Successfully killed the mitmproxy playback process
10:03:24     INFO -  raptor-mitmproxy Turning off the browser proxy
10:03:24     INFO -  raptor-main removing webext /home/cltbld/workspace/build/tests/raptor/webext/raptor
10:03:24    ERROR -  Traceback (most recent call last):
10:03:24     INFO -    File "/home/cltbld/workspace/build/tests/raptor/raptor/raptor.py", line 349, in <module>
10:03:24     INFO -      main()
10:03:24     INFO -    File "/home/cltbld/workspace/build/tests/raptor/raptor/raptor.py", line 327, in main
10:03:24     INFO -      raptor.run_test(next_test, timeout=int(next_test['page_timeout']))
10:03:24     INFO -    File "/home/cltbld/workspace/build/tests/raptor/raptor/raptor.py", line 259, in run_test
10:03:24     INFO -      self.profile.addons.remove_addon(webext_id)
10:03:24     INFO -    File "/home/cltbld/workspace/build/venv/lib/python2.7/site-packages/mozprofile/addons.py", line 329, in remove_addon
10:03:24     INFO -      path = self.get_addon_path(addon_id)
10:03:24     INFO -    File "/home/cltbld/workspace/build/venv/lib/python2.7/site-packages/mozprofile/addons.py", line 108, in get_addon_path
10:03:24     INFO -      raise IOError('Add-on not found: %s' % addon_id)
10:03:24     INFO -  IOError: Add-on not found: [e-mail]

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Robert, please take a look and decide what should be done with tp6 on beta. Thank you.

Comment 2

[Joel Maher ( :jmaher ) (UTC -8)]

:aryx, is this perma fail?  why did it work on a beta simulation last week?

Comment 3

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

It's a permafail and the job added last week was "Rap-C-..." which is raptor-chrome (which passes), we need raptor-firefox.

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

:aswan for our testing web extensions on mozilla-beta, how do we sign them?  you have been converting many talos extensions to be web extensions, here is our raptor web extension: https://searchfox.org/mozilla-central/source/testing/raptor/webext/raptor

Comment 5

[Andrew Swan [:aswan]]

Ideally we wouldn't sign something that's used in automation.  How were talos-powers and pageloader handled prior to switching from talos to raptor?

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

I believe it was a pref and env var:
pref: security.turn_off_all_security_so_that_viruses_can_take_over_this_computer=true
env: self.env['MOZ_DISABLE_NONLOCAL_CONNECTIONS'] = '1'

I see the pref set for raptor, but not the env var, although for tp6 I thought we had to turn off the env var to start with since we would spoof dns for all traffic that was recorded.

:aswan, does this sound right?

Comment 7

[Andrew Swan [:aswan]]

Yes, the combination of that pref and that environment variable (plus a few other prefs like xpinstall.signatures.enabled and extensions.legacy.enabled) will allow unsigned privileged extensions to run on beta.  But as you say, one of the talos tests (tp5 or tp6 or both?) uses mitmproxy and so cannot set the DISABLE_NONLOCAL_CONNECTIONS env var.
I'm a little lost here, are we talking about a test that was previously running on beta with talos or about enabling a new test that we haven't ever run on beta before?

Comment 8

[Joel Maher ( :jmaher ) (UTC -8)]

thanks for the clarification :aswan.

tp6 was perma failing on beta (windows only), we will be running tp6 in raptor soon, so we decided to run raptor-tp6 on mozilla-beta instead of talos tp6.  Now we find that raptor tp6 is failing due to signing.  I will look into this with :rwood when he is back from pto; I think we need to figure out why tp6 worked on beta 2 weeks ago running in talos and why this fails now in raptor.  Maybe this is related to some of the addons -> extension work.


here is a push from Monday showing talos tp6 failures:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&searchStr=tp6&revision=aba25ceab10f829e07c36ab1fd9fdbb83d4774c2

from the log of win10, I see:
14:54:17     INFO -  PID 6520 | 1540220057112	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
14:54:17     INFO -  PID 6520 | 1540220057115	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
[taskcluster:error] Aborting task...


this would explain why we hit max timeout and aborted the tasks- the addons were not properly signed- but why on windows only?  no errors like that in the linux logs.

Comment 9

[Robert Wood [:rwood]]

Ugh, this is starting to show up on Raptor jobs on Windows 10 on try now [1] (in a totally unrelated change):

20:43:34     INFO -  PID 7288 | 1540413814455	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
20:43:34     INFO -  PID 7288 | 1540413814455	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
20:43:34     INFO -  PID 7288 | 1540413814455	addons.xpi-utils	WARN	addMetadata: Add-on [e-mail] is invalid: Error: Extension [e-mail] is not correctly signed(resource://gre/modules/addons/XPIDatabase.jsm:2426:17) JS Stack trace: [e-mail]:2426:17

So something has definitely changed in Firefox, that is not letting our webext load.

[1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=550a25adb6816e772a2a46757773533f54826000&selectedJob=207615797

Comment 10

[Robert Wood [:rwood]]

Also on OSX on try too, so it's not just Win.

14:13:36     INFO -  PID 584 | 1540415616659	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
14:13:36     INFO -  PID 584 | 1540415616659	addons.xpi-utils	WARN	Add-on [e-mail] is not correctly signed.
14:13:36     INFO -  PID 584 | 1540415616659	addons.xpi-utils	WARN	addMetadata: Add-on [e-mail] is invalid: Error: Extension [e-mail] is not correctly signed(resource://gre/modules/addons/XPIDatabase.jsm:2426:17) JS Stack trace: [e-mail]:2426:17

Comment 11

[Intermittent Failures Robot]

30 failures in 496 pushes (0.06 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-beta: 30

Platform breakdown:
* windows7-32: 5
* linux64-qr: 5
* windows10-64: 5
* osx-10-10: 5
* windows10-64-qr: 5
* linux64: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-24&endday=2018-10-24&tree=all

Comment 12

[Robert Wood [:rwood]]

Ah. So this was broken in Talos on beta even before Raptor was turned on in Beta. This looks like the change that originally introduced this problem on Talos (and seen on Raptor when it was turned on):

https://hg.mozilla.org/releases/mozilla-beta/rev/a6996c5491a5ff1f4aee11ceb090a3710c3a365a#l10.15

Comment 13

[Robert Wood [:rwood]]

(In reply to Robert Wood [:rwood] from comment #12)
> Ah. So this was broken in Talos on beta even before Raptor was turned on in
> Beta. This looks like the change that originally introduced this problem on
> Talos (and seen on Raptor when it was turned on):
> 
> https://hg.mozilla.org/releases/mozilla-beta/rev/a6996c5491a5ff1f4aee11ceb090a3710c3a365a#l10.15

SO if I am understanding correctly, it looks like for R64 this build config was changed:

-# Disable enforcing that add-ons are signed by the trusted root
-MOZ_REQUIRE_SIGNING=${MOZ_REQUIRE_SIGNING-0}
+# Enable enforcing that add-ons are signed by the trusted root
+MOZ_REQUIRE_SIGNING=${MOZ_REQUIRE_SIGNING-1}

And that is causing our talos (and raptor) webext not to be able to load.

:aswan, :jmaher, any idea about this setting or how we can get around it? There's no bug associated with that merge/change so I really don't know whom to ask or how to find out why this setting was turned on etc.

Comment 14

[Andrew Swan [:aswan]]

Signing has been required on beta for some time, I suspect that's a patch that gets applied automatically every time we uplift from central to beta.  As I said earlier, I have no idea how this ever worked, other bits of automation use the combination Joel mentioned in comment 6 but tp6 wants to use non-local network connections so I have no idea how it ever worked on beta.

Comment 15

[Robert Wood [:rwood]]

Thanks Andrew. 

Maybe there was something in the merge commit immediately before that, that caused this change in behaviour - before the merge for R64 talos tp6 was running fine on beta:

https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&searchStr=talos%2Ctp6&tochange=a6996c5491a5ff1f4aee11ceb090a3710c3a365a&fromchange=2704bbd93c5655757d331b7463bcbf49ab497956

Comment 16

[Andrew Swan [:aswan]]

Ryan, can you help us understand what's going on here?

Comment 17

[(PTO June 19-July 7) Ryan VanderMeulen]

I don't know what you're asking me for here. All comment 15 is saying is that it worked when 63 was on Beta and doesn't with 64. I have no idea what might have changed over the course of that development cycle to make that be the case. With some hackery, you could probably try to bisect it on Try, but I don't have cycles to help there.

And yes, that MOZ_REQUIRE_SIGNING change is something we do on every merge day, it's not new to 64.

Comment 18

[Andrew Swan [:aswan]]

Sorry for the vague question Ryan.  The MOZ_REQUIRE_SIGNING change appears to be a red herring.

Here's an old (arbitrarily chosen) beta run where the tests passed:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&searchStr=talos%2Ctp6&revision=095138ddfce66ad816470b4f0132e700d859f00a

But signing was required in that build:
https://hg.mozilla.org/releases/mozilla-beta/file/095138ddfce66ad816470b4f0132e700d859f00a/build/mozconfig.common

Comment 19

[Robert Wood [:rwood]]

Ahh: in the merge was the change in Bug 1493867 to convert talos pageloader to a webext... so talos tp6 on beta (green) before that was when it was the old pageloader add-on.

Comment 20

[Andrew Swan [:aswan]]

Its still not clear to me how the old pageloader extension worked on beta.  Even if there's some signed copy of it laying around somewhere, it was a bootstrapped extension, which we don't allow to run on beta.

Comment 21

[Robert Wood [:rwood]]

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

Comment 22

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=43b51d27b7a11a6038716e689870401d385a45ce

Comment 23

[Robert Wood [:rwood]]

(In reply to Robert Wood [:rwood] from comment #22)

> https://treeherder.mozilla.org/#/jobs?repo=try&revision=43b51d27b7a11a6038716e689870401d385a45ce

I can reproduce the issue in Raptor tp6 on try by setting the MOZ_REQUIRE_SIGNING=${MOZ_REQUIRE_SIGNING-1} config to emulate beta, but interesting on try that doesn't cause the same failure on talos tp6.

Comment 24

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=2c5a13630132be590a34465ca5cfd01400dfb449

Comment 25

[Intermittent Failures Robot]

28 failures in 448 pushes (0.063 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-beta: 28

Platform breakdown:
* windows10-64: 4
* windows10-64-qr: 8
* linux64-qr: 4
* osx-10-10: 4
* linux64: 4
* windows7-32: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-25&endday=2018-10-25&tree=all

Comment 26

[Intermittent Failures Robot]

16 failures in 411 pushes (0.039 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-beta: 12
* try: 4

Platform breakdown:
* windows10-64: 2
* osx-10-10: 4
* windows10-64-qr: 2
* linux64-qr: 3
* linux64: 3
* windows7-32: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-26&endday=2018-10-26&tree=all

Comment 27

[Intermittent Failures Robot]

93 failures in 2584 pushes (0.036 failures/push) were associated with this bug in the last 7 days.

This is the #18 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:
* try: 11
* mozilla-beta: 82

Platform breakdown:
* osx-10-10: 17
* windows10-64: 13
* windows10-64-qr: 17
* linux64: 16
* linux64-qr: 16
* windows7-32: 14

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-22&endday=2018-10-28&tree=all

Comment 28

[Intermittent Failures Robot]

18 failures in 443 pushes (0.041 failures/push) were associated with this bug yesterday.

Repository breakdown:
* mozilla-beta: 18

Platform breakdown:
* osx-10-10: 3
* windows10-64-qr: 3
* windows7-32: 3
* windows10-64: 3
* linux64-qr: 3
* linux64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-29&endday=2018-10-29&tree=all

Comment 29

[Robert Wood [:rwood]]

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

Comment 30

[Robert Wood [:rwood]]

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

Comment 31

[Robert Wood [:rwood]]

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

Comment 32

[Robert Wood [:rwood]]

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

Comment 33

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=4eb04bada8d0bba2b6dfe6e4f8309648810ed8db

Comment 34

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=3f7840679a20c5dfba18bb01ef2272a45f3628bc

Comment 35

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=53e178b5ae5aee6710fcc060747cfc52622b5010

Comment 36

[Robert Wood [:rwood]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=13d3c81d191e0172011d6ee7d357c9fa30c932bc

Comment 37

[Robert Wood [:rwood]]

(In reply to Robert Wood [:rwood] from comment #36)
> https://treeherder.mozilla.org/#/jobs?repo=try&revision=13d3c81d191e0172011d6ee7d357c9fa30c932bc

Good news: This solution seems to fix the issue without having to add an additional firefox startup/shutdown before the test.

On the try pushes I set the signing requirement in mozconfig.common like it is on mozilla-beta (+MOZ_REQUIRE_SIGNING=${MOZ_REQUIRE_SIGNING-1}) and this patch allows the unsigned webext to load anyway. I can't guarantee it would definitely fix the issue on mozilla-beta though until we run it there, but I think it's worth a go.

Comment 38

[Robert Wood [:rwood]]

Attachment: Bug 1501040 - Raptor fix so unsigned webext will load on mozilla-beta; r?jmaher

Comment 39

[Intermittent Failures Robot]

36 failures in 575 pushes (0.063 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. ** 

Repository breakdown:
* mozilla-beta: 36

Platform breakdown:
* osx-10-10: 6
* linux64: 6
* windows10-64-qr: 6
* windows7-32: 6
* windows10-64: 6
* linux64-qr: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-31&endday=2018-10-31&tree=all

Comment 40

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/236d1f315ea7
Raptor fix so unsigned webext will load on mozilla-beta; r=jmaher

Comment 41

[Daniel Varga [:dvarga]]

https://hg.mozilla.org/mozilla-central/rev/236d1f315ea7

Comment 42

[Intermittent Failures Robot]

40 failures in 559 pushes (0.072 failures/push) were associated with this bug yesterday.

Repository breakdown:
* try: 3
* mozilla-beta: 37

Platform breakdown:
* osx-10-10: 8
* linux64-qr: 7
* linux64: 7
* windows7-32: 6
* windows10-64-qr: 6
* windows10-64: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-11-01&endday=2018-11-01&tree=all

Comment 43

[Robert Wood [:rwood]]

Comment on attachment 9021719 [details]
Bug 1501040 - Raptor fix so unsigned webext will load on mozilla-beta; r?jmaher

[Beta/Release Uplift Approval Request]

Feature/Bug causing the regression: Bug 1501040

User impact if declined: 

Is this code covered by automated tests?: Yes

Has the fix been verified in Nightly?: Yes

Needs manual test from QE?: No

If yes, steps to reproduce: 

List of other uplifts needed: None

Risk to taking this patch: Low

Why is the change risky/not risky? (and alternatives if risky): 

String changes made/needed:

Comment 44

[Robert Wood [:rwood]]

This looks good on mozilla-central.

Comment 45

[(PTO June 19-July 7) Ryan VanderMeulen]

Comment on attachment 9021719 [details]
Bug 1501040 - Raptor fix so unsigned webext will load on mozilla-beta; r?jmaher

test-only changes don't need approval to be uplifted

Comment 46

[(PTO June 19-July 7) Ryan VanderMeulen]

https://hg.mozilla.org/releases/mozilla-beta/rev/560ec5d63826

Comment 47

[Intermittent Failures Robot]

118 failures in 2978 pushes (0.04 failures/push) were associated with this bug in the last 7 days.

This is the #7 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:
* mozilla-beta: 115
* try: 3

Platform breakdown:
* windows10-64: 19
* windows7-32: 19
* linux64: 20
* windows10-64-qr: 19
* linux64-qr: 20
* osx-10-10: 21

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1501040&startday=2018-10-29&endday=2018-11-04&tree=all

Comment 48

[Sylvestre Ledru [:Sylvestre]]

Issue in a script, fixed!