1607476 - Perma | toolkit/modules/tests/xpcshell/test_firstStartup.js | xpcshell return code: 0 when Gecko version increases to 75 on 2020-02-10

Multiple Authors

Description

•

5 years ago

•

Edited

[Tracking Requested - why for this release]:

Central as Version Increase simulation: https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=283826891&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel%2Crunnable&revision=91a10ab055d0141772ad67db49d218c853ab1a33

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=283826891&repo=try&lineNumber=2699

[task 2020-01-07T13:24:10.807Z] 13:24:10 [task 2020-01-07T13:24:12.196Z] 13:24:12 [task 2020-01-07T13:24:12.199Z] 13:24:12 [task 2020-01-07T13:24:12.208Z] 13:24:12 [task 2020-01-07T13:24:14.713Z] 13:24:14 [task 2020-01-07T13:24:14.728Z] 13:24:14 [task 2020-01-07T13:24:32.188Z] 13:24:32 [task 2020-01-07T13:24:32.203Z] 13:24:32 [task 2020-01-07T13:24:34.827Z] 13:24:34 [task 2020-01-07T13:24:34.834Z] 13:24:34 [task 2020-01-07T13:24:52.276Z] 13:24:52 [task 2020-01-07T13:24:52.292Z] 13:24:52 [task 2020-01-07T13:24:53.879Z] 13:24:53 [task 2020-01-07T13:24:53.894Z] 13:24:53 [task 2020-01-07T13:24:54.723Z] 13:24:54 [task 2020-01-07T13:24:54.724Z] 13:24:54 [task 2020-01-07T13:24:54.724Z] 13:24:54 [task 2020-01-07T13:24:54.724Z] 13:24:54 [task 2020-01-07T13:24:54.725Z] 13:24:54 [task 2020-01-07T13:24:54.725Z] 13:24:54 [task 2020-01-07T13:24:54.725Z] 13:24:54 [task 2020-01-07T13:24:54.726Z] 13:24:54 [task 2020-01-07T13:24:54.726Z] 13:24:54 [task 2020-01-07T13:24:54.726Z] 13:24:54 [task 2020-01-07T13:24:54.726Z] 13:24:54 [task 2020-01-07T13:24:54.727Z] 13:24:54 [task 2020-01-07T13:24:54.727Z] 13:24:54 [task 2020-01-07T13:24:54.727Z] 13:24:54 [task 2020-01-07T13:24:54.728Z] 13:24:54 [task 2020-01-07T13:24:54.729Z] 13:24:54 [task 2020-01-07T13:24:54.729Z] 13:24:54 [task 2020-01-07T13:24:54.729Z] 13:24:54 [task 2020-01-07T13:24:54.730Z] 13:24:54 [task 2020-01-07T13:24:54.731Z] 13:24:54 [task 2020-01-07T13:24:54.731Z] 13:24:54 [task 2020-01-07T13:24:54.731Z] 13:24:54 [task 2020-01-07T13:24:54.732Z] 13:24:54 [task 2020-01-07T13:24:54.732Z] 13:24:54 [task 2020-01-07T13:24:54.733Z] 13:24:54 [task 2020-01-07T13:24:54.733Z] 13:24:54 [task 2020-01-07T13:24:54.734Z] 13:24:54 [task 2020-01-07T13:24:54.734Z] 13:24:54 [task 2020-01-07T13:24:54.736Z] 13:24:54 [task 2020-01-07T13:24:54.736Z] 13:24:54 [task 2020-01-07T13:24:54.736Z] 13:24:54 INFO - TEST-START | uriloader/exthandler/tests/unit/test_punycodeURIs.js
INFO - TEST-PASS | uriloader/exthandler/tests/unit/test_punycodeURIs.js | took 1391ms
INFO - Retrying tests that failed when run in parallel.
INFO - TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_maybereloadengine_update.js
INFO - TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_maybereloadengine_update.js | took 2506ms
INFO - TEST-START | xpcshell-legacyconfig.ini:toolkit/components/search/tests/xpcshell/test_searchSuggest.js
INFO - TEST-PASS | xpcshell-legacyconfig.ini:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | took 17465ms
INFO - TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_maybereloadengine_update_distro.js
INFO - TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_maybereloadengine_update_distro.js | took 2628ms
INFO - TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_searchSuggest.js
INFO - TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | took 17441ms
INFO - TEST-START | toolkit/components/url-classifier/tests/unit/test_listmanager.js
INFO - TEST-PASS | toolkit/components/url-classifier/tests/unit/test_listmanager.js | took 1592ms
INFO - TEST-START | toolkit/modules/tests/xpcshell/test_firstStartup.js
WARNING - TEST-UNEXPECTED-FAIL | toolkit/modules/tests/xpcshell/test_firstStartup.js | xpcshell return code: 0
INFO - TEST-INFO took 833ms
INFO - >>>>>>>
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: Couldn't get the user appdata directory. Crash events may not be produced.: file /builds/worker/workspace/build/src/toolkit/crashreporter/nsExceptionHandler.cpp, line 2626
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: 'result.isErr()', file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 167
INFO - PID 18132 | [18132, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, kKnownEsrVersion) failed with result 0x80004002: file /builds/worker/workspace/build/src/toolkit/components/resistfingerprinting/nsRFPService.cpp, line 658
INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
INFO - running event loop
INFO - toolkit/modules/tests/xpcshell/test_firstStartup.js | Starting test_success
INFO - (xpcshell/head.js) | test test_success pending (2)
INFO - PID 18132 | JavaScript strict warning: resource://normandy/lib/RecipeRunner.jsm, line 120: ReferenceError: reference to undefined property "appBuildID"
INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "appBuildID"" {file: "resource://normandy/lib/RecipeRunner.jsm" line: 120}]"
INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "NetworkError when attempting to fetch resource." {file: "resource://gre/modules/FirstStartup.jsm" line: 59}]
INFO - init@resource://gre/modules/FirstStartup.jsm:59:19
INFO - test_success@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/modules/tests/xpcshell/test_firstStartup.js:14:16

Flags: needinfo?(rhelmer)

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

Comment 1

•

5 years ago

Test got added in bug 1576507.

Updated

•

5 years ago

Summary: TEST-UNEXPECTED-FAIL | toolkit/modules/tests/xpcshell/test_firstStartup.js | xpcshell return code: 0 when Gecko version increases to 75 on 2020-02-10 → Perma | toolkit/modules/tests/xpcshell/test_firstStartup.js | xpcshell return code: 0 when Gecko version increases to 75 on 2020-02-10

Comment hidden (Intermittent Failures Robot)

Robert Helmer [:rhelmer]

Assignee

Comment 3

•

5 years ago

Doug, I noticed the StartupCache.cpp warnings in the log for this FirstStartup test that is going to fail after merge (see comment 0), does any of this make sense to you?

I'll spend some time digging into it today too.

Flags: needinfo?(rhelmer) → needinfo?(dothayer)

Alex Thayer [:alexical] (she/her)

Comment 4

•

5 years ago

That's rather curious... do we somehow have multiple instances of the startup cache? That warning is from the destructor of the startup cache which should be a singleton. Am I missing something obvious here?

Robert Helmer [:rhelmer]

Assignee

Comment 5

•

5 years ago

(In reply to Doug Thayer [:dthayer] from comment #4)

That's rather curious... do we somehow have multiple instances of the startup cache? That warning is from the destructor of the startup cache which should be a singleton. Am I missing something obvious here?

Thanks! Maybe it's a side-effect of how the tests are being run... I'll take a look over previous logs and see if these warnings are something that happens in the non-failure case too.

Robert Helmer [:rhelmer]

Assignee

Comment 6

•

5 years ago

Oh, I had missed this on the first read-through:

task 2020-01-07T13:24:54.734Z] 13:24:54 INFO - PID 18132 | JavaScript strict warning: resource://normandy/lib/RecipeRunner.jsm, line 120: ReferenceError: reference to undefined property "appBuildID"

mythmon, any idea why that might be happening during FirstStartup tests ^?

Flags: needinfo?(dothayer) → needinfo?(mcooper)

Michael Cooper [:mythmon]

Comment 7

•

5 years ago

•

Edited

Normandy checks Services.appinfo.appBuildID to see if Firefox has upgraded and it needs to run again immediately. This change was introduced recently in bug 1472097.

I'm not sure why appBuildID would be undefined. That warning would have the effect of something like Services.prefs.setCharPref("...", undefined), which is probably not good. I have no idea why this would be triggered by a version bump to 75 though. We could try and add some safety around that block of code with something like this patch, but I'd like to figure out why it is doing that:

diff --git a/toolkit/components/normandy/lib/RecipeRunner.jsm b/toolkit/components/normandy/lib/RecipeRunner.jsm
--- a/toolkit/components/normandy/lib/RecipeRunner.jsm
+++ b/toolkit/components/normandy/lib/RecipeRunner.jsm
@@ -110,15 +110,18 @@ var RecipeRunner = {
     // If we've seen a build ID from a previous run that doesn't match the
     // current build ID, run immediately. This is probably an upgrade or
     // downgrade, which may cause recipe eligibility to change.
-    let lastSeenBuildID = Services.prefs.getCharPref(LAST_BUILDID_PREF, "");
-    let hasNewBuildID =
-      lastSeenBuildID && Services.appinfo.appBuildID != lastSeenBuildID;
+    let hasNewBuildID = false;
+    if (Services.appinfo.appBuildID) {
+      let lastSeenBuildID = Services.prefs.getCharPref(LAST_BUILDID_PREF, "");
+      hasNewBuildID =
+        lastSeenBuildID && Services.appinfo.appBuildID != lastSeenBuildID;
 
-    if (hasNewBuildID || !lastSeenBuildID) {
-      Services.prefs.setCharPref(
-        LAST_BUILDID_PREF,
-        Services.appinfo.appBuildID
-      );
+      if (hasNewBuildID || !lastSeenBuildID) {
+        Services.prefs.setCharPref(
+          LAST_BUILDID_PREF,
+          Services.appinfo.appBuildID
+        );
+      }
     }

Flags: needinfo?(mcooper)

BugBot [:suhaib / :marco/ :calixte]

Comment 8

•

5 years ago

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression

Comment hidden (Intermittent Failures Robot)

Liz Henry (:lizzard) (relman/hg->git project)

Comment 10

•

5 years ago

Are you taking on this bug? Or, can you help find an owner for it? Thanks!

tracking-firefox74: ? → +

Flags: needinfo?(mcooper)

Robert Helmer [:rhelmer]

Assignee

Comment 11

•

5 years ago

(In reply to Liz Henry (:lizzard) from comment #10)

Are you taking on this bug? Or, can you help find an owner for it? Thanks!

I'll take a look.

Assignee: nobody → rhelmer

Status: NEW → ASSIGNED

Robert Helmer [:rhelmer]

Assignee

Updated

•

5 years ago

Flags: needinfo?(mcooper)

Robert Helmer [:rhelmer]

Assignee

Comment 12

•

5 years ago

Could you please tell me how to reproduce this? I tried taking the patch from https://hg.mozilla.org/try/rev/91a10ab055d0141772ad67db49d218c853ab1a33 on a current m-c but I don't see it locally or on full try builds. What am I missing?

Flags: needinfo?(shindli)

Robert Helmer [:rhelmer]

Assignee

Comment 13

•

5 years ago

(In reply to Robert Helmer [:rhelmer] from comment #12)

Could you please tell me how to reproduce this? I tried taking the patch from https://hg.mozilla.org/try/rev/91a10ab055d0141772ad67db49d218c853ab1a33 on a current m-c but I don't see it locally or on full try builds. What am I missing?

Oops never mind, I see it on try now.

Flags: needinfo?(shindli)

Robert Helmer [:rhelmer]

Assignee

Comment 14

•

5 years ago

Hm. So the actual failure is:

[task 2020-01-16T22:43:19.351Z] 22:43:19 INFO - Unexpected exception TypeError: right-hand side of 'in' should be an object, got undefined at /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/modules/tests/xpcshell/test_firstStartup.js:23

Still not seeing it locally though, will poke some telemetry folk.

Robert Helmer [:rhelmer]

Assignee

Comment 15

•

5 years ago

Ugh OK the problem here is just that the telemetry probes expired :/ I'll put a patch up today.

BugBot [:suhaib / :marco/ :calixte]

Comment 16

•

5 years ago

The priority flag is not set for this bug.
:Dolske, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(dolske)

Julien Cristau [:jcristau]

Updated

•

5 years ago

Flags: needinfo?(dolske) → needinfo?(rhelmer)

Priority: -- → P1

Robert Helmer [:rhelmer]

Assignee

Comment 17

•

5 years ago

Attached file Bug 1607476 - update expiration for FirstStartup scalars r?chutten — Details

Robert Helmer [:rhelmer]

Assignee

Comment 18

•

5 years ago

Try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=6f230b5d4a40b5e7628cfa23b5fc9145c2e04771&selectedJob=285722467

Flags: needinfo?(rhelmer)

Robert Helmer [:rhelmer]

Assignee

Comment 19

•

5 years ago

Attached file Data Collection Renewal for Bug 1607476 — Details

Attachment #9122588 - Flags: data-review?(chutten)

Chris H-C :chutten

Comment 20

•

5 years ago

Comment on attachment 9122588 [details] Data Collection Renewal for Bug 1607476 Is the provided Data Collection Review complete, correct, and data-review+ by a Data Steward? Yes. Is the data collection covered by the existing Firefox Privacy Notice? Yes. --- Result: datareview+

Attachment #9122588 - Flags: data-review?(chutten) → data-review+

Pulsebot

Comment 21

•

5 years ago

Pushed by rhelmer@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/9610ac8f69e4 update expiration for FirstStartup scalars r=chutten

Andreea Pavel [:apavel]

Comment 22

•

5 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/9610ac8f69e4

Status: ASSIGNED → RESOLVED

Closed: 5 years ago

status-firefox74: affected → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla74

Cosmin Sabou [:CosminS]

Comment 23

•

5 years ago

Fix verified in today's version increase simulation: https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&resultStatus=success%2Ctestfailed%2Cbusted%2Cexception%2Cusercancel%2Crunnable&revision=9601c58e8991f23fc2a442a37819feae731864f3&searchStr=xpc

Status: RESOLVED → VERIFIED

status-firefox74: fixed → verified

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

Updated

•

5 years ago

Bug 1607476 - update expiration for FirstStartup scalars r?chutten 5 years ago Robert Helmer [:rhelmer] 47 bytes, text/x-phabricator-request		Details \| Review
Data Collection Renewal for Bug 1607476 5 years ago Robert Helmer [:rhelmer] 942 bytes, text/plain	chutten : data-review+	Details