Closed Bug 1523923 Opened 10 months ago Closed 8 months ago

Intermittent Assertion failure: rv, at z:/build/build/src/nsprpub/pr/src/md/windows/w95thred.c:276

Categories

(Core :: WebVR, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla67
Tracking Status
firefox-esr60 --- unaffected
firefox65 --- unaffected
firefox66 --- wontfix
firefox67 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: daoshengmu)

References

Details

(Keywords: assertion, intermittent-failure)

Attachments

(1 file)

#[markdown(off)]
Filed by: rgurzau [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=224939040&repo=try

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

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/aRA7oopBSlyLKcqLLH4UIw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

12:18:51 INFO - JavaScript error: resource://reftest/reftest.jsm, line 1558: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString]
12:18:51 INFO - [Parent 5612, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:51 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:51 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
12:18:51 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:51 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:51 INFO - [Child 4700, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 869
12:18:51 INFO - nsStringStats
12:18:51 INFO - => mAllocCount: 6221
12:18:51 INFO - => mReallocCount: 0
12:18:51 INFO - => mFreeCount: 6221
12:18:51 INFO - => mShareCount: 4639
12:18:51 INFO - => mAdoptCount: 71
12:18:51 INFO - => mAdoptFreeCount: 71
12:18:51 INFO - => Process ID: 4700, Thread ID: 5740
12:18:52 INFO - 1548850732210 Marionette TRACE Received observer notification xpcom-will-shutdown
12:18:52 INFO - 1548850732210 Marionette INFO Stopped listening on port 2828
12:18:52 INFO - 1548850732211 Marionette DEBUG Remote service is inactive
12:18:52 INFO - [Parent 5612, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file z:/build/build/src/netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1284
12:18:52 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
12:18:52 INFO - [Parent 5612, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - [Parent 5612, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - [GPU 5032, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
12:18:52 INFO - [GPU 5032, Compositor] WARNING: VRThread::Shutdown() may only be called from an XPCOM thread: file z:/build/build/src/gfx/vr/VRThread.cpp, line 57
12:18:52 INFO - Assertion failure: rv, at z:/build/build/src/nsprpub/pr/src/md/windows/w95thred.c:276
12:18:52 INFO - [Parent 5612, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 869
12:18:52 INFO - nsStringStats
12:18:52 INFO - => mAllocCount: 1238
12:18:52 INFO - => mReallocCount: 0
12:18:52 INFO - => mFreeCount: 1238
12:18:52 INFO - => mShareCount: 296
12:18:52 INFO - => mAdoptCount: 0
12:18:52 INFO - => mAdoptFreeCount: 0
12:18:52 INFO - => Process ID: 5032, Thread ID: 6620

Immediately prior to the assertion:
WARNING: VRThread::Shutdown() may only be called from an XPCOM thread: file z:/build/build/src/gfx/vr/VRThread.cpp, line 57

The timing of this bug lines up exactly with bug 1514417 landing (and I found this today after it was uplifted to Beta as another data point).

Kip, can you please take a look since dmu is on PTO?

Blocks: 1514417
Component: NSPR → WebVR
Flags: needinfo?(kgilbert)
Keywords: assertion
Product: NSPR → Core
QA Contact: jjones
Version: other → unspecified

I guess we should shutdown the VRThread (mSubmitThread) early when calling StopPresentation() instead of ~VRDisplayHost(). Sorry for I am away from my device to help verify.

(In reply to Ryan VanderMeulen [:RyanVM] from comment #2)

Immediately prior to the assertion:
WARNING: VRThread::Shutdown() may only be called from an XPCOM thread: file z:/build/build/src/gfx/vr/VRThread.cpp, line 57

The timing of this bug lines up exactly with bug 1514417 landing (and I found this today after it was uplifted to Beta as another data point).

Kip, can you please take a look since dmu is on PTO?

I'll take this one. Thanks for the tip, Daosheng!

Assignee: nobody → kgilbert
Flags: needinfo?(kgilbert)

Take Bug 1310152 Comment 9 as the reference, I am wondering we might shutdown the VR thread while it is still running submit frame tasks. We can test it with ./mach test dom/vr/test/reftest/change_size.html --repeat=20

I pushed to try the parent of that push:

No Bug, mozilla-beta repo-update HSTS HPKP remote-settings - a=repo-update r=RyanVM

and the assertion seems to trigger on R2 (instead of R1)

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

In the failure cases, the last test seems to be:

REFTEST TEST-END | file:///Z:/task_1550515971/build/tests/reftest/tests/dom/vr/test/reftest/change_size.html == file:///Z:/task_1550515971/build/tests/reftest/tests/dom/vr/test/reftest/wrapper.html?change_size.png

Flags: needinfo?(edilee)

Looks like it was failing in R4 from https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=229138827&revision=1b92df3fb13a3bab6365213a6290c7b8b25dc98d originally pushed on the 16th, but looking back more, it looks like it was failing from at least the 7th:

https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&searchStr=10-64%2Fdebug-reftest-e10s-4&revision=d7e94ba9dbad1189eeb1fbb4ea1f456668b23381&selectedJob=226885498

That push does contain 9b74b2602df1 DM Bug 1514417 - Using named mutex for VR threads to access Shmem on Windows. r=kip, a=lizzard as mentioned in comment 2.

I am trying to use CancelableRunnable as VR submit frame tasks, and it looks better in local. I am waiting for the actual try results after the Treeherder be opened.

It looks like it would be resolved in Nightly after applying my WIP patch. :Markdak, could you help me verify it, https://treeherder.mozilla.org/#/jobs?repo=try&revision=8dfe4775de479bdd7732ff21d7b299b7c54c1bc8?

Thanks,

Flags: needinfo?(edilee)

R4 on that try included reftest/tests/dom/vr/test/reftest/change_size.html so I retriggered a bunch and looks like they're all passing.

Flags: needinfo?(edilee)

Assigning to Daosheng, who has a WIP patch for this issue.

Assignee: kgilbert → dmu
Pushed by dmu@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/249fb9b3679b
Cancel VR submit frame tasks when the VRDisplayHost is destroyed. r=kip
Status: NEW → RESOLVED
Closed: 9 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67

Please request Beta approval on this when you get a chance.

Flags: needinfo?(dmu)

Comment on attachment 9045699 [details]
Bug 1523923 - Cancel VR submit frame tasks when the VRDisplayHost is destroyed.

Beta/Release Uplift Approval Request

  • Feature/Bug causing the regression: Bug 1514417
  • User impact if declined: The intermittent assertion failure on Bug 1523923 will continue to happen
  • 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): It is used to fix the intermittent assertion and has been verified in Nightly.
  • String changes made/needed:
Flags: needinfo?(dmu)
Attachment #9045699 - Flags: approval-mozilla-beta?
Blocks: 1528365
No longer blocks: 1528365
Depends on: 1530663
See Also: → 1528365

Comment on attachment 9045699 [details]
Bug 1523923 - Cancel VR submit frame tasks when the VRDisplayHost is destroyed.

We are investigating some new bugs that caused by this. I will give a uplift request later.

Attachment #9045699 - Flags: approval-mozilla-beta?
Depends on: 1530489

Given that we are getting closer to 66 release, might it be better to back this out in nightly?

(In reply to Liz Henry (:lizzard) (use needinfo) from comment #23)

Given that we are getting closer to 66 release, might it be better to back this out in nightly?

This haven't be uplift to beta, and we also have patches on our hands already, we will fix them soon.

Correct, we count a bug as RESOLVED FIXED when it is fixed in the current nightly version. We depend on the status-firefoxXX:affected flags to settle what will happen on beta, release, and esr60 branches.

Looks like there was no request to bring it to beta, so I think comment 25 is just a mistake. I will mark this as fix-optional for 66, and please let me know if you think we need uplift to beta when you are ready.

Status: REOPENED → RESOLVED
Closed: 9 months ago9 months ago
Resolution: --- → FIXED

Given that next week is RC week for 66, we should probably just let this ride the trains at this point given the fallout from it.

Let's not uplift to beta :)

Flags: needinfo?(lhenry)

I am waiting for Bug 1530663's landing. Once Bug 1530663 is landed, I am going to consider to give a uplift for this bug.

Flags: needinfo?(dmu)
See Also: → 1522358

New failure in beta: https://treeherder.mozilla.org/#/jobs?repo=mozilla-beta&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&selectedJob=232670311

Log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=232670311&repo=mozilla-beta&lineNumber=67215

15:04:05 INFO - => Process ID: 9480, Thread ID: 11288
15:04:05 INFO - 1552057445227 Marionette TRACE Received observer notification xpcom-will-shutdown
15:04:05 INFO - 1552057445227 Marionette INFO Stopped listening on port 2828
15:04:05 INFO - 1552057445228 Marionette DEBUG Remote service is inactive
15:04:05 INFO - [Parent 864, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file z:/build/build/src/netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1284
15:04:05 INFO - [GPU 4632, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
15:04:05 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
15:04:05 INFO - [GPU 4632, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
15:04:05 INFO - [Parent 864, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
15:04:05 INFO - [GPU 4632, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
15:04:05 INFO - [GPU 4632, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
15:04:05 INFO - [GPU 4632, Compositor] WARNING: VRThread::Shutdown() may only be called from an XPCOM thread: file z:/build/build/src/gfx/vr/VRThread.cpp, line 57
15:04:05 INFO - Assertion failure: rv, at z:/build/build/src/nsprpub/pr/src/md/windows/w95thred.c:276
15:04:05 INFO - [Parent 864, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 869
15:04:05 INFO - nsStringStats
15:04:05 INFO - => mAllocCount: 1221
15:04:05 INFO - => mReallocCount: 0
15:04:05 INFO - => mFreeCount: 1221
15:04:05 INFO - => mShareCount: 292
15:04:05 INFO - => mAdoptCount: 0
15:04:05 INFO - => mAdoptFreeCount: 0
15:04:05 INFO - => Process ID: 4632, Thread ID: 10104

Status: RESOLVED → REOPENED
Resolution: FIXED → ---

Beta is 66, not 67. This patch wasn't backported there.

Status: REOPENED → RESOLVED
Closed: 9 months ago8 months ago
Resolution: --- → FIXED
Depends on: 1534390

:lizzard, we are considering to uplift this bug fix to FF 66, and it needs to uplift its dependent bugs,
Bug 1530489, Bug 1530663, and Bug 1534390 too. I know it is a little late to take the train FF 66, but it is probably worth because it will resolve a few try fails and the stability problem at the current mozilla-beta channel. If you are ok, I will give a request soon.

Flags: needinfo?(lhenry)

It is too late for 66, We built the release candidate yesterday, and while we are doing one more build this looks too complex for the last minute. I think it needs time on 67 (which will be on mozilla-beta next Monday)

Flags: needinfo?(lhenry)
You need to log in before you can comment on or make changes to this bug.