Closed Bug 1515761 Opened 5 years ago Closed 5 years ago

Intermittent toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | A promise chain failed to handle a rejection: Cannot modify properties of a WrappedNative

Categories

(Toolkit :: Application Update, defect, P5)

defect

Tracking

()

RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Assigned: robert.strong.bugs)

References

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered])

Filed by: cbrindusan [at] mozilla.com

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

https://queue.taskcluster.net/v1/task/KyXho6-8SOOKrb9fH0T7Lg/runs/0/artifacts/public/logs/live_backing.log

18:06:57     INFO - TEST-START | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateManager:_loadXMLFileIntoArray - update xml file updates.xml exists but doesn't contain any updates
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
18:06:57     INFO - GECKO(4684) | *** AUS:SVC isServiceInstalled - returning true
18:06:57     INFO - GECKO(4684) | *** AUS:SVC shouldUseService - returning true
18:06:57     INFO - GECKO(4684) | *** AUS:SVC getCanApplyUpdates - bypass the write checks because the Windows Maintenance Service can be used
18:06:57     INFO - GECKO(4684) | *** AUS:SVC readStatusFile - status: failed: 4, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - GECKO(4684) | *** AUS:SVC readStringFromFile - file doesn't exist: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\bt.result
18:06:57     INFO - GECKO(4684) | *** AUS:SVC readBinaryTransparencyResult - result: null, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\bt.result
18:06:57     INFO - GECKO(4684) | *** AUS:SVC handleFallbackToCompleteUpdate - install of partial patch failed, downloading complete patch
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Creating Downloader
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateService:_downloadUpdate
18:06:57     INFO - GECKO(4684) | *** AUS:SVC readStringFromFile - file doesn't exist: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - GECKO(4684) | *** AUS:SVC readStatusFile - status: null, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:_selectPatch - found existing patch with state: null
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:downloadUpdate - url: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.mar, interval: 0
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateManager:_writeUpdatesToXMLFile - Exception: Win error 183 during operation rename on file C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates.xml (Cannot create a file when that file already exists.
18:06:57     INFO - GECKO(4684) | )
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Unable to write to critical update file: updates.xml
18:06:57     INFO - GECKO(4684) | JavaScript error: jar:file:///Z:/task_1545326839/build/application/firefox/omni.ja!/components/nsUpdateService.js, line 1121: NS_ERROR_XPC_CANT_MODIFY_PROP_ON_WN: Cannot modify properties of a WrappedNative
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStartRequest - original URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, final URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onProgress - progress: 1404/1404
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onProgress - progress: 1404 is higher than patch size: 1234
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader: cancel
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onProgress - progress: 1404/1404
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onProgress - progress: 1404 is higher than patch size: 1234
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader: cancel
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStopRequest - original URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, final URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, status: 2147549183
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStopRequest - status: 2147549183, current fail: 0, max fail: 10, retryTimeout: 2000
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStopRequest - non-verification failure
18:06:57     INFO - GECKO(4684) | *** AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStopRequest - setting state to: download-failed
18:06:57     INFO - GECKO(4684) | *** AUS:SVC Downloader:onStopRequest - notifying observers of error. topic: update-error, status: download-attempts-exceeded, downloadAttempts: 1 maxAttempts: 0
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - GECKO(4684) | *** AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - TEST-INFO | started process screenshot
18:06:57     INFO - TEST-INFO | screenshot: exit 0
18:06:57     INFO - Buffered messages logged at 18:06:56
18:06:57     INFO - Entering test bound setDefaults
18:06:57     INFO - Buffered messages logged at 18:06:57
18:06:57     INFO - Leaving test bound setDefaults
18:06:57     INFO - Entering test bound testPartialPatchApplyFailureWithCompleteValidationFailure
18:06:57     INFO - Console message: AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - Console message: AUS:SVC UpdateManager:_loadXMLFileIntoArray - update xml file updates.xml exists but doesn't contain any updates
18:06:57     INFO - Console message: AUS:SVC UpdateService.canCheckForUpdates - able to check for updates
18:06:57     INFO - Console message: AUS:SVC isServiceInstalled - returning true
18:06:57     INFO - Console message: AUS:SVC shouldUseService - returning true
18:06:57     INFO - Console message: AUS:SVC getCanApplyUpdates - bypass the write checks because the Windows Maintenance Service can be used
18:06:57     INFO - Console message: AUS:SVC readStatusFile - status: failed: 4, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - Console message: AUS:SVC readStringFromFile - file doesn't exist: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\bt.result
18:06:57     INFO - Console message: AUS:SVC readBinaryTransparencyResult - result: null, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\bt.result
18:06:57     INFO - Console message: AUS:SVC handleFallbackToCompleteUpdate - install of partial patch failed, downloading complete patch
18:06:57     INFO - Console message: AUS:SVC Creating Downloader
18:06:57     INFO - Console message: AUS:SVC UpdateService:_downloadUpdate
18:06:57     INFO - Console message: AUS:SVC readStringFromFile - file doesn't exist: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - Console message: AUS:SVC readStatusFile - status: null, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.status
18:06:57     INFO - Console message: AUS:SVC Downloader:_selectPatch - found existing patch with state: null
18:06:57     INFO - Console message: AUS:SVC Downloader:downloadUpdate - url: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, path: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates\0\update.mar, interval: 0
18:06:57     INFO - Console message: AUS:SVC UpdateManager:_writeUpdatesToXMLFile - Exception: Win error 183 during operation rename on file C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\updates.xml (Cannot create a file when that file already exists.
18:06:57     INFO - )
18:06:57     INFO - Console message: AUS:SVC Unable to write to critical update file: updates.xml
18:06:57     INFO - Console message: [JavaScript Error: "NS_ERROR_XPC_CANT_MODIFY_PROP_ON_WN: Cannot modify properties of a WrappedNative" {file: "jar:file:///Z:/task_1545326839/build/application/firefox/omni.ja!/components/nsUpdateService.js" line: 1121}]
18:06:57     INFO - Console message: AUS:SVC Downloader:onStartRequest - original URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, final URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar
18:06:57     INFO - Console message: AUS:SVC Downloader:onProgress - progress: 1404/1404
18:06:57     INFO - Console message: AUS:SVC Downloader:onProgress - progress: 1404 is higher than patch size: 1234
18:06:57     INFO - Console message: AUS:SVC Downloader: cancel
18:06:57     INFO - Console message: AUS:SVC Downloader:onProgress - progress: 1404/1404
18:06:57     INFO - Console message: AUS:SVC Downloader:onProgress - progress: 1404 is higher than patch size: 1234
18:06:57     INFO - Console message: AUS:SVC Downloader: cancel
18:06:57     INFO - Console message: AUS:SVC Downloader:onStopRequest - original URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, final URI spec: http://example.com/browser/toolkit/mozapps/update/tests/browser/simple.mar, status: 2147549183
18:06:57     INFO - Console message: AUS:SVC Downloader:onStopRequest - status: 2147549183, current fail: 0, max fail: 10, retryTimeout: 2000
18:06:57     INFO - Console message: AUS:SVC Downloader:onStopRequest - non-verification failure
18:06:57     INFO - Console message: AUS:SVC getStatusTextFromCode - transfer error: Failed (unknown reason), default code: 2152398849
18:06:57     INFO - Console message: AUS:SVC Downloader:onStopRequest - setting state to: download-failed
18:06:57     INFO - Console message: AUS:SVC Downloader:onStopRequest - notifying observers of error. topic: update-error, status: download-attempts-exceeded, downloadAttempts: 1 maxAttempts: 0
18:06:57     INFO - Console message: AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - Console message: AUS:SVC UpdateManager:_writeUpdatesToXMLFile - no updates to write. removing file: C:\ProgramData\Mozilla\updates\B3515A4BCBEFFEB8\active-update.xml
18:06:57     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | The right notification showed up. - 
18:06:57     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | update-manual notification is showing - 
18:06:57     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | What's new link points to the test_details URL - 
18:06:57     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | What's new link is not hidden. - 
18:06:57     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | Landed on manual update page. - 
18:06:57     INFO - Buffered messages finished
18:06:57     INFO - TEST-UNEXPECTED-FAIL | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | A promise chain failed to handle a rejection: Cannot modify properties of a WrappedNative - stack: handleCriticalWriteFailure@jar:file:///Z:/task_1545326839/build/application/firefox/omni.ja!/components/nsUpdateService.js:1121:9
Note: Bug 1515726, Bug 1515761, Bug 1515848, Bug 1515998, Bug 1516004, Bug 1516049, and Bug 1516079 all started failing around the same time.
This started failing with this merge to central: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&searchStr=4cc381bea492cb926cd2bb3be67c683d7708be23&group_state=expanded&revision=c668b3a05a6404c577466838f04370d541cc25ce&selectedJob=219314412


14:49:18     INFO - TEST-PASS | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | Landed on manual update page. - 
14:49:18     INFO - Buffered messages finished
14:49:18     INFO - TEST-UNEXPECTED-FAIL | toolkit/mozapps/update/tests/browser/browser_updatesPartialPatchApplyFailureWithCompleteValidationFailure.js | A promise chain failed to handle a rejection: Cannot modify properties of a WrappedNative - stack: handleCriticalWriteFailure@jar:file:///Z:/task_1546177750/build/application/firefox/omni.ja!/components/nsUpdateService.js:1121:9
14:49:18     INFO - handleCriticalWriteResult@jar:file:///Z:/task_1546177750/build/application/firefox/omni.ja!/components/nsUpdateService.js:1179:5
14:49:18     INFO - UM__saveUpdatesXML/<@jar:file:///Z:/task_1546177750/build/application/firefox/omni.ja!/components/nsUpdateService.js:2902:30
14:49:18     INFO - Rejection date: Sun Dec 30 2018 14:49:18 GMT+0000 (GMT) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 257
14:49:18     INFO - Stack trace:
14:49:18     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
14:49:18     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1131
14:49:18     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1097
14:49:18     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:995
14:49:18     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:focusedOrLoaded/<:803
14:49:18     INFO - Leaving test bound testPartialPatchApplyFailureWithCompleteValidationFailure
14:49:18     INFO - GECKO(2776) | MEMORY STAT | vsize 767MB | vsizeMaxContiguous 745MB | residentFast 269MB | heapAllocated 111MB

After looking a bit through the stack trace and the bugs merged to central with that push I would take a guess and say it's from these modifications: https://hg.mozilla.org/mozilla-central/rev/fbf8034d81325271d3fb4c68d14e018d0dbb6053, Bug 1498775.

Tooru could you please take a look over this? Thank you.
Flags: needinfo?(arai.unmht)
Basically, all these bugs are pre-existing errors which has been overlooked because the error is not reported due to the issue fixed by bug 1498775.
I'll take a look next week.
arai, thanks and I'll take this though I'll probably fix it in a different bug. I got a patch that is almost done.
Robert, do you have any updates on this? It has moved into the disable-recommended area and has 167 failures since 20th december.
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2018-12-07&endday=2019-01-06&tree=all&bug=1515761
Can we go ahead and disable this or do you have a fix for it? Thank you.
Flags: needinfo?(robert.strong.bugs)
I should have a patch reviewed and landed by Tuesday
Flags: needinfo?(robert.strong.bugs)
Depends on: 1499004
Flags: needinfo?(arai.unmht)

I hope to fix this in bug 1499004

Assignee: nobody → robert.strong.bugs
Status: NEW → ASSIGNED

Cosmin, just an FYI that there are two failures that are under android-em-4-3-armv7-api16 but none of these tests doesn't even run on android.

Robert, those were not classified by us but by a developer by mistake.

Thanks and no worries... just wanted to give sheriffs a heads up

(In reply to Cosmin Sabou [:CosminS] from comment #11)

Robert, do you have any updates on this? It has moved into the
disable-recommended area and has 167 failures since 20th december.
https://treeherder.mozilla.org/intermittent-failures.html#/
bugdetails?startday=2018-12-07&endday=2019-01-06&tree=all&bug=1515761
Can we go ahead and disable this or do you have a fix for it? Thank you.
I landed this on inbound earlier today and so far there have been no failures so it is looking good.

Meant to say bug 1499004 landed on inbound

Robert, thank you for working on this. We'll keep an eye on the failure rate after the fix.

Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered]

The only failures since bug 1499004 landed were from a single try push at 2019-01-10 00:10:46 that didn't include the patch from bug 1499004.

Resolving as fixed

Status: ASSIGNED → RESOLVED
Closed: 5 years ago
Resolution: --- → FIXED
Whiteboard: [retriggered][stockwell disable-recommended] → [retriggered]
You need to log in before you can comment on or make changes to this bug.