1661137 - Intermittent printing/<random>.html | assertion count 1 is more than expected 0 assertions after ASSERTION: User did not call nsIContentViewer::Destroy: '!mPresShell && !mPresContext', file /builds/worker/checkouts/gecko/layout/base/nsDocumentViewer.cpp

Status: RESOLVED FIXED

(Core :: Printing: Output, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: rmaries [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=313997971&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UuO_QiCtRRSuMq7izDfVAg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/UuO_QiCtRRSuMq7izDfVAg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

Comment 2

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

Using a bug separate from bug 827183.

Comment 5

[Emilio Cobos Álvarez (:emilio)]

I wonder if there's a pernosco recording of this.

Comment 8

[Emilio Cobos Álvarez (:emilio)]

Ugh, it won't because these are disabled on Linux... Will push some try runs with this enabled to see if I catch it.

Comment 9

[Emilio Cobos Álvarez (:emilio)]

Stack:

#13 0x000007a85baa987e in NS_DebugBreak(uint32_t, char const*, char const*, char const*, int32_t)
    (aSeverity=1, aStr=0x7a857a8f9ae "User did not call nsIContentViewer::Destroy", aExpr=0x7a857522f7c "!mPresShell && !mPresContext", aFile=0x7a8578a2000 "/home/emilio/src/moz/gecko-2/layout/base/nsDocumentViewer.cpp", aLine=574) at /home/emilio/src/moz/gecko-2/xpcom/base/nsDebugImpl.cpp:366
#14 0x000007a85eed57cb in nsDocumentViewer::~nsDocumentViewer() (this=0x9aa12589900) at /home/emilio/src/moz/gecko-2/layout/base/nsDocumentViewer.cpp:573
#15 0x000007a85eed6162 in nsDocumentViewer::~nsDocumentViewer() (this=0x9aa12589900) at /home/emilio/src/moz/gecko-2/layout/base/nsDocumentViewer.cpp:559
#16 0x000007a85eed5522 in nsDocumentViewer::Release() (this=0x9aa12589900) at /home/emilio/src/moz/gecko-2/layout/base/nsDocumentViewer.cpp:547
#17 0x000007a85f207cec in nsPagePrintTimer::~nsPagePrintTimer() (this=0x6febd280) at /home/emilio/src/moz/gecko-2/layout/printing/nsPagePrintTimer.cpp:17
#18 0x000007a85bb87119 in mozilla::Runnable::Release() (this=0x6febd280) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsThreadUtils.cpp:68
#19 0x000007a85bb8808c in nsTimerImpl::Callback::clear() (this=0x7ffe6e6f2f10) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.h:107
#20 nsTimerImpl::Callback::~Callback() (this=0x7ffe6e6f2f10) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.h:104
#21 nsTimerImpl::Fire(int) (this=0x6fe9a190, aGeneration=1) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.cpp:597
#22 0x000007a85bb87d34 in nsTimerEvent::Run() (this=0x6fed5140) at /home/emilio/src/moz/gecko-2/xpcom/threads/TimerThread.cpp:251

Comment 10

[Emilio Cobos Álvarez (:emilio)]

It is the print document, set here, but the docshell gets destroyed before the print finishes:

#0  nsCOMPtr<nsIContentViewer>::assign_assuming_AddRef(nsIContentViewer*) (this=0x17046a731aa0, aNewPtr=0x0) at /home/emilio/src/moz/gecko-2/obj-debug-no-sccache/dist/include/nsCOMPtr.h:413
#1  nsCOMPtr<nsIContentViewer>::operator=(decltype(nullptr)) (this=0x17046a731aa0) at /home/emilio/src/moz/gecko-2/obj-debug-no-sccache/dist/include/nsCOMPtr.h:684
#2  nsDocShell::Destroy() (this=0x17046a731800) at /home/emilio/src/moz/gecko-2/docshell/base/nsDocShell.cpp:4223
#3  0x000007a85fe9f50a in nsWebBrowser::SetDocShell(nsDocShell*) (this=0x6fe8b4c0, aDocShell=0x0) at /home/emilio/src/moz/gecko-2/toolkit/components/browser/nsWebBrowser.cpp:1131
#4  0x000007a85fe9ec41 in nsWebBrowser::InternalDestroy() (this=0x6fe8b4c0) at /home/emilio/src/moz/gecko-2/toolkit/components/browser/nsWebBrowser.cpp:174
#5  0x000007a85fea1a8b in non-virtual thunk to nsWebBrowser::Destroy() () at /home/emilio/src/moz/gecko-2/toolkit/components/browser/nsWebBrowser.cpp:855

We do call nsDocumentViewer::Destroy from there, but we hit this condition and thus keep stuff alive.

That "blocked destroy count" gets decremented here, right before dropping the content viewer entirely:

#0  0x000007a85eedf5db in non-virtual thunk to nsDocumentViewer::DecrementDestroyBlockedCount() () at /home/emilio/src/moz/gecko-2/layout/base/nsDocumentViewer.cpp:3727
#1  0x000007a85f207c8e in nsPagePrintTimer::~nsPagePrintTimer() (this=0x6febd280) at /home/emilio/src/moz/gecko-2/layout/printing/nsPagePrintTimer.cpp:19
#2  0x000007a85f207cec in nsPagePrintTimer::~nsPagePrintTimer() (this=0x6febd280) at /home/emilio/src/moz/gecko-2/layout/printing/nsPagePrintTimer.cpp:17
#3  0x000007a85bb87119 in mozilla::Runnable::Release() (this=0x6febd280) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsThreadUtils.cpp:68
#4  0x000007a85bb8808c in nsTimerImpl::Callback::clear() (this=0x7ffe6e6f2f10) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.h:107
#5  nsTimerImpl::Callback::~Callback() (this=0x7ffe6e6f2f10) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.h:104
#6  nsTimerImpl::Fire(int) (this=0x6fe9a190, aGeneration=1) at /home/emilio/src/moz/gecko-2/xpcom/threads/nsTimerImpl.cpp:597
#7  0x000007a85bb87d34 in nsTimerEvent::Run() (this=0x6fed5140) at /home/emilio/src/moz/gecko-2/xpcom/threads/TimerThread.cpp:251
#8  0x000007a85bb7994d in mozilla::SchedulerGroup::Runnable::Run() (this=0x6fea84c0) at /home/emilio/src/moz/gecko-2/xpcom/threads/SchedulerGroup.cpp:146
#9  0x000007a85bb80255 in mozilla::RunnableTask::Run() (this=0x6febd900) at /home/emilio/src/moz/gecko-2/xpcom/threads/TaskController.cpp:242

By the time we close the window, we're already done, nsPagePrintTimer::mDone is true.

Comment 11

[Emilio Cobos Álvarez (:emilio)]

Attachment: Bug 1661137 - Decrement the document viewer's destroy blocker earlier. r=bobowen

Do it as soon as we're done printing, rather than waiting until the
print timer dies.

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/ede12aa1b8b5
Decrement the document viewer's destroy blocker earlier. r=bobowen

Comment 13

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1636728

Comment 14

[Razvan Maries]

Backed out for perma failures.

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedTaskRun=WmF9Fi1PRgSB86EVtowM1Q.0&resultStatus=testfailed%2Cbusted%2Cexception&revision=dd7fb8f29da26ebcd74febb515588efe97e964fc&failure_classification_id=2

Logs:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=314278143&repo=autoland&lineNumber=39433
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=314278756&repo=autoland&lineNumber=60520

Backout: https://hg.mozilla.org/integration/autoland/rev/cd9583400fea833d307c7b95a97498a82561999c

Comment 15

[Intermittent Failures Robot]

31 failures in 4046 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

This is the #22 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: 27
• mozilla-central: 4

Platform breakdown:

• macosx1014-64-qr: 14
• macosx1014-64: 17

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1661137&startday=2020-08-24&endday=2020-08-30&tree=all

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/e6ef511d20c9
Decrement the document viewer's destroy blocker earlier. r=bobowen

Comment 17

[Narcis Beleuzu [:NarcisB]]

https://hg.mozilla.org/mozilla-central/rev/e6ef511d20c9

Comment 18

[Jonathan Watt [:jwatt]]

Comment on attachment 9172635 [details]
Bug 1661137 - Decrement the document viewer's destroy blocker earlier. r=bobowen

Beta/Release Uplift Approval Request

• User impact if declined: Printing project
• Is this code covered by automated tests?: No
• 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: Medium
• Why is the change risky/not risky? (and alternatives if risky):
• String changes made/needed:

Comment 19

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9172635 [details]
Bug 1661137 - Decrement the document viewer's destroy blocker earlier. r=bobowen

Approved for 81.0b6.

Comment 20

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/6081b620e74f

Comment 21

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 3

Platform breakdown:

• macosx1014-64: 2
• macosx1014-64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1661137&startday=2020-08-31&endday=2020-09-06&tree=all