Closed Bug 1426807 Opened 6 years ago Closed 6 years ago

[a11y] Crash in mozilla::gfx::RecordedSetTransform::PlayEvent when print with "Microsoft Print to PDF" and "Microsoft XPS Document Writer"

Categories

(Core :: Security: Process Sandboxing, defect, P1)

59 Branch
x86_64
Windows 10
defect

Tracking

()

VERIFIED FIXED
mozilla60
Tracking Status
firefox-esr52 --- unaffected
firefox57 --- unaffected
firefox58 --- unaffected
firefox59 + verified
firefox60 --- verified

People

(Reporter: alice0775, Assigned: Alex_Gaynor)

References

Details

(Keywords: crash, regression, reproducible, Whiteboard: sb+)

Crash Data

Attachments

(1 file, 1 obsolete file)

This bug was filed from the Socorro interface and is
report bp-0b61c4cb-8ee1-4d06-9369-002700171222.
=============================================================

Top 10 frames of crashing thread:

0 xul.dll mozilla::gfx::RecordedSetTransform::PlayEvent gfx/2d/RecordedEventImpl.h:2185
1 xul.dll mozilla::layout::PrintTranslator::TranslateRecording layout/printing/PrintTranslator.cpp:60
2 xul.dll mozilla::layout::RemotePrintJobParent::PrintPage layout/printing/ipc/RemotePrintJobParent.cpp:142
3 xul.dll mozilla::layout::RemotePrintJobParent::RecvProcessPage layout/printing/ipc/RemotePrintJobParent.cpp:123
4 xul.dll mozilla::layout::PRemotePrintJobParent::OnMessageReceived ipc/ipdl/PRemotePrintJobParent.cpp:240
5 xul.dll mozilla::dom::PContentParent::OnMessageReceived ipc/ipdl/PContentParent.cpp:3286
6 xul.dll mozilla::ipc::MessageChannel::DispatchAsyncMessage ipc/glue/MessageChannel.cpp:2110
7 xul.dll mozilla::ipc::MessageChannel::DispatchMessageW ipc/glue/MessageChannel.cpp:2040
8 xul.dll mozilla::ipc::MessageChannel::RunMessage ipc/glue/MessageChannel.cpp:1886
9 xul.dll mozilla::ipc::MessageChannel::MessageTask::Run ipc/glue/MessageChannel.cpp:1919

=============================================================

I can reproduce the crash on Nightly59.0a1 x64 windows10.


Reproducible: always

Steps To Reproduce:
1. Open twitter 
        e.g. https://twitter.com/d_toybox  not need login
2. Print with Microsoft Print to PDF. 
3. Input file name, then click on Save button

Actual Results:
Browser crashes


Regression window:
https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=c7633e5266c0da789ce4503fb0a09979efa2580d&tochange=87f5eb24ef4b510fa73db427e80bc011f6160bde

Regressed by: 87f5eb24ef4b	Alex Gaynor — Bug 1414834 - re-land print IPC changes from bug 1319423; r=bobowen

@:Alex_Gaynor
Your patch seems to cause crash regression. Can you look into this?
Flags: needinfo?(agaynor)
Has Regression Range: --- → yes
Has STR: --- → yes
the following page is also affected
https://github.com/piroor (no need login)
Microsoft XPS Document Writer is also affected.
Summary: Crash in mozilla::gfx::RecordedSetTransform::PlayEvent → Crash in mozilla::gfx::RecordedSetTransform::PlayEvent when print with "Microsoft Print to PDF" and "Microsoft XPS Document Writer"
Crash Signature: [@ mozilla::gfx::RecordedSetTransform::PlayEvent] → [@ mozilla::gfx::RecordedSetTransform::PlayEvent] [@ mozilla::gfx::DrawTargetSkia::SetTransform ]
I was unable to reproduce this on a Windows 10 debug build at rev ac93fdadf102 with either of the URLs you provided (both Print to PDF and XPS Document Writer)

Are there any other relevant details you can suggest for me to attempt to reproduce this?
Flags: needinfo?(agaynor) → needinfo?(alice0775)
(In reply to Alex Gaynor [:Alex_Gaynor] from comment #3)
> I was unable to reproduce this on a Windows 10 debug build at rev
> ac93fdadf102 with either of the URLs you provided (both Print to PDF and XPS
> Document Writer)
> 
> Are there any other relevant details you can suggest for me to attempt to
> reproduce this?

I can still reproduce the crash on Latest Nightly59.0a1(https://hg.mozilla.org/mozilla-central/rev/ac93fdadf1022211eec62258ad22b42cb37a6d14). And reproduced on the debug build too.

I tested with clean profile.

You should need a11y activated such as Narrator, ATOK2016(Japanese IME).


Steps To Reproduce with Narrator:
0. Start Menu > Settings > Ease of Access > Narrator
     then Enable Narrator by clicking on the Narrator switch button.
1. Open twitter 
        e.g. https://twitter.com/d_toybox  not need login
2. Alt > File > Print > Microsoft Print to PDF > OK
3. Input file name, then click on Save button
Flags: needinfo?(alice0775)
Summary: Crash in mozilla::gfx::RecordedSetTransform::PlayEvent when print with "Microsoft Print to PDF" and "Microsoft XPS Document Writer" → [a11y] Crash in mozilla::gfx::RecordedSetTransform::PlayEvent when print with "Microsoft Print to PDF" and "Microsoft XPS Document Writer"
You should need a11y activated such as Narrator or ATOK2016(Japanese IME).
Flags: needinfo?(agaynor)
[Tracking Requested - why for this release]: It is time to back the offending patches(Bug 1414834) out before Nightly59.0 becomes Beta.
Thanks for the precise instructions, I'm attempting to reproduce and will report back!
Flags: needinfo?(agaynor)
Reproduced! I'm still awfully confused, but now I have a debugger, so the world is my oyster!
Ok, I added a bunch of logging to the serialization, and I'm now incredibly confused, would appreciate some insight from folks who know the 2d serialization stuff better (Jeff, hopefully you're the right person for this, if not any pointers to the right person would be appreciated).

I specifically added logging in the following places:

- RecordedDrawTargetCreation::Record & RecordedCreateSimilarDrawTarget::Record - These are the two places that serialize structures which can lead to the creation of a draw target on deserialization.
- PrintTranslator::LookupDrawTarget, PrintTranslator::AddDrawTarget, PrintTranslator::RemoveDrawTarget - which are the places that interact with mDrawTargets on PrintTranslator

Having added this logging, I get the following output:

RecordedDrawTargetCreation::Record - mRefPtr=<Addr X>
AddDrawTarget - aRefPtr=<Addr X>
LookupDrawTarget- aRefPtr=<Addr X>
LookupDrawTarget- aRefPtr=<Addr X>
LookupDrawTarget- aRefPtr=<Addr Y>

This explains the crash we're seeing -- that LookupDrawTarget cannot find an entry for that RefPtr in mDrawTargets.

I'm not familiar enough with this code, why would we be looking for a RefPtr that doesn't exist? Is this bug likely to be because we lost a call to RecordedDrawTargetCreation::Record or RecordedCreateSimilarDrawTarget::Record, or because we generated a call to LookupDrawTarget with a bad address? Any suggestions for how to investigate more deeply, I don't understand how the commit that regressed this could have effected anything :-)
Flags: needinfo?(jmuizelaar)
Do you know what's calling LookupDrawTarget() with the bad RefPtr?
Flags: needinfo?(jmuizelaar) → needinfo?(agaynor)
Flags: needinfo?(jmuizelaar)
RecordedSetTransform::PlayEvent. I'm going to go add some logging on the RecordedSetTransform::Record side to see what it shows.
Flags: needinfo?(agaynor)
Ok, what I see is:

RecordedDrawTargetCreation::Record - mrefPtr=<Addr X>
RecordedSetTransform::Record       - mDt=    <Addr X>
RecordedSetTransform::Record       - mDt=    <Addr X>
RecordedSetTransform::Record       - mDt=    <Addr Y> (repeats like 5 times)
RecordedSetTransform::Record       - mDt=    <Addr X> (repeats like 400 times)

AddDrawTarget:    aRefPtr=<Addr X>
LookupDrawTarget: aRefPtr=<Addr X>
LookupDrawTarget: aRefPtr=<Addr X>
LookupDrawTarget: aRefPtr=<Addr Y>

So I _think_ the question is, whose responsibility was it to make sure a RecordedDrawTargetCreation or RecordedCreateSimilarDrawTarget happened? (Or maybe the question is "Why are there RecordedSetTransforms" for a different DrawTarget, not sure!)
Is it possible to get a stack trace on RecordedSetTransform::Record       - mDt=    <Addr Y> (repeats like 5 times)?
The 8 frames above RecordedSetTrasnform for Addr Y are:

  mozilla::gfx::RecordedSetTransform::Record<mozilla::gfx::EventStream>
  mozilla::gfx::RecordedEventDerived<mozilla::gfx::RecordedSetTransform>::RecordToStream
  mozilla::layout::DrawEventRecorderPRFileDesc::RecordEvent
  mozilla::gfx::DrawTargetWrapAndRecord::SetTransform
  gfxContext::gfxContext
  gfxContext::CreateOrNull
  nsDeviceContext::CreateRenderingContextCommon
  nsDeviceContext::CreateReferenceRenderingContext

If you want more frames, let me know :-)
I suspect if you do some logging of DrawTargetRecording creation/destruction along with DrawEventRecorder creation/destruction it will become more clear what's going on. My gut feeling is something weird is happening there.
Flags: needinfo?(jmuizelaar)
Ok, now I'm very confused. This is printing three pages, and it's the second page that causes the crash.

RecordedSetTransform::Record with mDt=<Addr Y> is on the second page. However, it corresponds to the a RecordedDrawTargetCreation::Record from the _first_ page!

So, somehow, we're trying to record an event from a previous "epoch". Your gut feeling is confirmed :-). The full stack looks like:

  mozilla::gfx::RecordedSetTransform::Record<mozilla::gfx::EventStream>
  mozilla::gfx::RecordedEventDerived<mozilla::gfx::RecordedSetTransform>::RecordToStream
  mozilla::layout::DrawEventRecorderPRFileDesc::RecordEvent
  mozilla::gfx::DrawTargetWrapAndRecord::SetTransform
  gfxContext::gfxContext
  gfxContext::CreateOrNull
  nsDeviceContext::CreateRenderingContextCommon
  nsDeviceContext::CreateReferenceRenderingContext
  mozilla::PresShell::CreateReferenceRenderingContext
  mozilla::css::LazyReferenceRenderingDrawTargetGetterFromFrame::GetRefDrawTarget
  gfxFontGroup::GetEllipsisTextRun
  mozilla::css::GetEllipsisTextRun
  mozilla::css::TextOverflow::Marker::SetupString
  mozilla::css::TextOverflow::ExamineLineFrames
  mozilla::css::TextOverflow::ProcessLine
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  DisplayLine
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  nsContainerFrame::DisplayOverflowContainers
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  nsContainerFrame::DisplayOverflowContainers
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  nsContainerFrame::DisplayOverflowContainers
  nsBlockFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  nsCanvasFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForChild
  mozilla::ViewportFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForStackingContext
  nsPageFrame::BuildDisplayList
  nsIFrame::BuildDisplayListForStackingContext
  nsLayoutUtils::PaintFrame
  nsSimplePageSequenceFrame::PrintNextPage
  nsPrintJob::PrintPage
  nsPagePrintTimer::Run
  mozilla::SchedulerGroup::Runnable::Run
  nsThread::ProcessNextEvent
  NS_ProcessNextEvent
  mozilla::ipc::MessagePump::Run
  mozilla::ipc::MessagePumpForChildProcess::Run
Is the PrintTargetThebes being reused? I suspect your reusing a DrawTargetRecording with another DrawTargetRecording that has a different recorder.

If you look at https://searchfox.org/mozilla-central/source/gfx/thebes/PrintTargetThebes.cpp#60 it seems like it could return a DrawTarget that doesn't have the same DrawEventRecorder* aRecorder as is passed in.
I'm not sure if they're reused, it seems like a pretty solid bet though. I don't understand why my IPC patch causes this, or why a11y is needed to trigger it. Bob, is this familiar to you at all?
Flags: needinfo?(bobowencode)
(In reply to Alex Gaynor [:Alex_Gaynor] from comment #18)
> I'm not sure if they're reused, it seems like a pretty solid bet though. I
> don't understand why my IPC patch causes this, or why a11y is needed to
> trigger it. Bob, is this familiar to you at all?

The recorder should be the same for the whole print job I believe, because we can definitely use things recorded in a previous page (for example fonts).

I wonder if I was wrong about my remark at the end of bug 1319423 comment 34 and we do need to be recording things before the first BeginPage (not sure why that would only surface in these circumstances and on the second page though).
Hmm, maybe it's the creation of mRefDT, given that it looks like this is cached and possibly is created before the first BeginPage.
Flags: needinfo?(bobowencode)
Assignee: nobody → agaynor
Priority: -- → P1
Whiteboard: sb+
Bob, good call! I stuck an `if (!IsOpen()) { DebugBreak(); }` at the top of DrawEventRecorderPRFielDesc::RecordEvent and it triggers. Here's what the stack looks like:

 # Child-SP          RetAddr           Call Site
00 00000071`b81f6678 00007ffa`0d4d8f05 KERNELBASE!wil::details::DebugBreak+0x2
01 00000071`b81f6680 00007ffa`08e79d5c xul!mozilla::layout::DrawEventRecorderPRFileDesc::RecordEvent+0x25 [c:\mozilla-source\mozilla-central\layout\printing\draweventrecorder.cpp @ 20]
02 00000071`b81f66c0 00007ffa`08dc266b xul!mozilla::gfx::DrawTargetWrapAndRecord::DrawTargetWrapAndRecord+0x28c [c:\mozilla-source\mozilla-central\gfx\2d\drawtargetwrapandrecord.cpp @ 296]
03 00000071`b81f67f0 00007ffa`08dc96e7 xul!mozilla::MakeAndAddRef<mozilla::gfx::DrawTargetWrapAndRecord,mozilla::gfx::DrawEventRecorder * __ptr64 & __ptr64,mozilla::gfx::DrawTarget * __ptr64 & __ptr64>+0x5b [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\dist\include\mozilla\refptr.h @ 649]
04 00000071`b81f6840 00007ffa`0944fd57 xul!mozilla::gfx::Factory::CreateWrapAndRecordDrawTarget+0x27 [c:\mozilla-source\mozilla-central\gfx\2d\factory.cpp @ 414]
05 00000071`b81f6880 00007ffa`09453267 xul!mozilla::gfx::PrintTarget::CreateWrapAndRecordDrawTarget+0xc7 [c:\mozilla-source\mozilla-central\gfx\thebes\printtarget.cpp @ 208]
06 00000071`b81f69d0 00007ffa`08f406f8 xul!mozilla::gfx::PrintTargetThebes::GetReferenceDrawTarget+0x217 [c:\mozilla-source\mozilla-central\gfx\thebes\printtargetthebes.cpp @ 73]
07 00000071`b81f6a90 00007ffa`08f40520 xul!nsDeviceContext::CreateRenderingContextCommon+0x178 [c:\mozilla-source\mozilla-central\gfx\src\nsdevicecontext.cpp @ 391]
08 00000071`b81f6d80 00007ffa`0cecb6d7 xul!nsDeviceContext::CreateReferenceRenderingContext+0x20 [c:\mozilla-source\mozilla-central\gfx\src\nsdevicecontext.cpp @ 376]
09 00000071`b81f6db0 00007ffa`0d1bfed5 xul!mozilla::PresShell::CreateReferenceRenderingContext+0xd7 [c:\mozilla-source\mozilla-central\layout\base\presshell.cpp @ 3048]
0a 00000071`b81f6e40 00007ffa`0d1c5620 xul!CreateReferenceDrawTarget+0x35 [c:\mozilla-source\mozilla-central\layout\generic\nstextframe.cpp @ 2040]
0b 00000071`b81f6e90 00007ffa`0d1ce25f xul!nsTextFrame::EnsureTextRun+0xa0 [c:\mozilla-source\mozilla-central\layout\generic\nstextframe.cpp @ 2868]
0c 00000071`b81f6f50 00007ffa`0f4b4123 xul!nsTextFrame::GetRenderedText+0x1ef [c:\mozilla-source\mozilla-central\layout\generic\nstextframe.cpp @ 10035]
0d 00000071`b81f7150 00007ffa`0f4afb19 xul!nsAccessibilityService::CreateAccessible+0x473 [c:\mozilla-source\mozilla-central\accessible\base\nsaccessibilityservice.cpp @ 1114]
0e 00000071`b81f7440 00007ffa`0f4c9f61 xul!mozilla::a11y::TreeWalker::AccessibleFor+0xe9 [c:\mozilla-source\mozilla-central\accessible\base\treewalker.cpp @ 339]
0f 00000071`b81f7480 00007ffa`0f4dfc8f xul!mozilla::a11y::TreeWalker::Next+0x1f1 [c:\mozilla-source\mozilla-central\accessible\base\treewalker.cpp @ 183]
10 00000071`b81f74f0 00007ffa`0f4e55a9 xul!mozilla::a11y::DocAccessible::CacheChildrenInSubtree+0xef [c:\mozilla-source\mozilla-central\accessible\generic\docaccessible.cpp @ 2340]
11 00000071`b81f7c80 00007ffa`0f44ae9d xul!mozilla::a11y::DocAccessible::DoInitialUpdate+0x2e9 [c:\mozilla-source\mozilla-central\accessible\generic\docaccessible.cpp @ 1513]
12 00000071`b81f7d70 00007ffa`0f49fae2 xul!mozilla::a11y::DocAccessibleWrap::DoInitialUpdate+0x2d [c:\mozilla-source\mozilla-central\accessible\windows\msaa\docaccessiblewrap.cpp @ 148]
13 00000071`b81f7ef0 00007ffa`0ce9c6ae xul!mozilla::a11y::NotificationController::WillRefresh+0x2f2 [c:\mozilla-source\mozilla-central\accessible\base\notificationcontroller.cpp @ 666]
14 00000071`b81f8300 00007ffa`0ce9e0ae xul!nsRefreshDriver::Tick+0x6ee [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 1864]
15 00000071`b81f8b70 00007ffa`0ce9e6ee xul!mozilla::RefreshDriverTimer::TickDriver+0x9e [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 337]
16 00000071`b81f8bf0 00007ffa`0ce9bed8 xul!mozilla::RefreshDriverTimer::TickRefreshDrivers+0xee [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 308]
17 00000071`b81f8c90 00007ffa`0ce9a7d8 xul!mozilla::RefreshDriverTimer::Tick+0x188 [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 330]
18 00000071`b81f8d70 00007ffa`0ce9e4e6 xul!mozilla::VsyncRefreshDriverTimer::RunRefreshDrivers+0x98 [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 770]
19 00000071`b81f8e10 00007ffa`0ce97af4 xul!mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::TickRefreshDriver+0x1b6 [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 685]
1a 00000071`b81f8f10 00007ffa`0d3976f5 xul!mozilla::VsyncRefreshDriverTimer::RefreshDriverVsyncObserver::NotifyVsync+0x284 [c:\mozilla-source\mozilla-central\layout\base\nsrefreshdriver.cpp @ 586]
1b 00000071`b81f8fd0 00007ffa`081f534d xul!mozilla::layout::VsyncChild::RecvNotify+0x105 [c:\mozilla-source\mozilla-central\layout\ipc\vsyncchild.cpp @ 70]
1c 00000071`b81f9040 00007ffa`080651cc xul!mozilla::layout::PVsyncChild::OnMessageReceived+0x26d [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\ipc\ipdl\pvsyncchild.cpp @ 155]
1d 00000071`b81f9190 00007ffa`07c4bc4d xul!mozilla::ipc::PBackgroundChild::OnMessageReceived+0x9c [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\ipc\ipdl\pbackgroundchild.cpp @ 1812]
1e 00000071`b81f9790 00007ffa`07c4c2d1 xul!mozilla::ipc::MessageChannel::DispatchAsyncMessage+0x11d [c:\mozilla-source\mozilla-central\ipc\glue\messagechannel.cpp @ 2110]
1f 00000071`b81f97f0 00007ffa`07c592e6 xul!mozilla::ipc::MessageChannel::DispatchMessageW+0x271 [c:\mozilla-source\mozilla-central\ipc\glue\messagechannel.cpp @ 2042]
20 00000071`b81f98e0 00007ffa`07c590c5 xul!mozilla::ipc::MessageChannel::RunMessage+0x1c6 [c:\mozilla-source\mozilla-central\ipc\glue\messagechannel.cpp @ 1887]
21 00000071`b81f9930 00007ffa`070c4b38 xul!mozilla::ipc::MessageChannel::MessageTask::Run+0xc5 [c:\mozilla-source\mozilla-central\ipc\glue\messagechannel.cpp @ 1920]
22 00000071`b81f9970 00007ffa`070ddff6 xul!nsThread::ProcessNextEvent+0x7f8 [c:\mozilla-source\mozilla-central\xpcom\threads\nsthread.cpp @ 1041]
23 00000071`b81fa070 00007ffa`0d4c47e3 xul!NS_ProcessNextEvent+0x76 [c:\mozilla-source\mozilla-central\xpcom\threads\nsthreadutils.cpp @ 517]
24 00000071`b81fa0b0 00007ffa`0d4d4959 xul!mozilla::SpinEventLoopUntil<1,<lambda_6a83974847ad29faff056eba2ac39191> >+0x53 [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\dist\include\nsthreadutils.h @ 323]
25 00000071`b81fa100 00007ffa`0c8dd411 xul!mozilla::layout::RemotePrintJobChild::InitializePrint+0x69 [c:\mozilla-source\mozilla-central\layout\printing\ipc\remoteprintjobchild.cpp @ 36]
26 00000071`b81fa150 00007ffa`08f3fde8 xul!nsDeviceContextSpecProxy::BeginDocument+0xd1 [c:\mozilla-source\mozilla-central\widget\nsdevicecontextspecproxy.cpp @ 142]
27 00000071`b81fa1e0 00007ffa`0d4de222 xul!nsDeviceContext::BeginDocument+0x118 [c:\mozilla-source\mozilla-central\gfx\src\nsdevicecontext.cpp @ 527]
28 00000071`b81fa240 00007ffa`0d4cee68 xul!nsPrintJob::SetupToPrintContent+0xc72 [c:\mozilla-source\mozilla-central\layout\printing\nsprintjob.cpp @ 1916]
29 00000071`b81fa580 00007ffa`0d4c9550 xul!nsPrintJob::DocumentReadyForPrinting+0x68 [c:\mozilla-source\mozilla-central\layout\printing\nsprintjob.cpp @ 1568]
2a 00000071`b81fa5c0 00007ffa`0d4d4700 xul!nsPrintJob::AfterNetworkPrint+0x180 [c:\mozilla-source\mozilla-central\layout\printing\nsprintjob.cpp @ 2033]
2b 00000071`b81fa630 00007ffa`0d4d655c xul!nsPrintJob::InitPrintDocConstruction+0x120 [c:\mozilla-source\mozilla-central\layout\printing\nsprintjob.cpp @ 2008]
2c 00000071`b81fa6a0 00007ffa`0faf070c xul!nsPrintJob::Observe+0x2c [c:\mozilla-source\mozilla-central\layout\printing\nsprintjob.cpp @ 3522]
2d 00000071`b81fa6e0 00007ffa`080dbada xul!mozilla::embedding::PrintProgressDialogChild::RecvDialogOpened+0x3c [c:\mozilla-source\mozilla-central\toolkit\components\printingui\ipc\printprogressdialogchild.cpp @ 45]
2e 00000071`b81fa720 00007ffa`085b32d2 xul!mozilla::embedding::PPrintProgressDialogChild::OnMessageReceived+0x12a [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\ipc\ipdl\pprintprogressdialogchild.cpp @ 193]
2f 00000071`b81fa7c0 00007ffa`0c307385 xul!mozilla::dom::PContentChild::OnMessageReceived+0xa2 [c:\mozilla-source\mozilla-central\obj-x86_64-pc-mingw32\ipc\ipdl\pcontentchild.cpp @ 4967]


So, what seems to be happening is that |RemotePrintJobChild| is initializing, which involves some IPC which it manually waits on. While it's waiting for the parent to send it some IPC back, VSync happens, and it does an accessibility thing, which triggers |CreateReferenceRenderingContext|... this is probably the first time it gets called, so it tries to emit the event, and then the write gets silently ignored.

There's a lot going on here, so it's hard for me to understand where the bug is, but my instinct is that it's one of the following:

- Accessibility stuff running and triggering draw events while we're waiting for printing to be initialized
- The accessibility draw events happening _on the printing rendering context_
- The fact that the DrawEventRecorder isn't ready to go right from the start.

I'd appreciate any thoughts folks had, as this is happening at the intersection of several different subsystems I don't understand super well :-)
(In reply to Alex Gaynor [:Alex_Gaynor] from comment #20)
> - The accessibility draw events happening _on the printing rendering context_

If this is happening that seems bad.
That's certainly what it looks like from the stack (bearing in mind I'm not an expert in an of rendering, printing, or a11y :P). Relevant frames: nsAccessibilityService::CreateAccessible -> nsTextFrame::GetRenderedText -> mozilla::PresShell::CreateReferenceRenderingContext -> mozilla::gfx::PrintTargetThebes::GetReferenceDrawTarget -> mozilla::gfx::DrawTargetWrapAndRecord::DrawTargetWrapAndRecord -> mozilla::layout::DrawEventRecorderPRFileDesc::RecordEvent
This is also sort of out my area. Perhaps Jonathan has a better idea what's going on?
Flags: needinfo?(jwatt)
This may look low volume until it hits release.  Tracking for 59. Looks like we still have a chance to clear this up in beta 59.
For what it's worth, I'm not convinced the "mozilla::gfx::DrawTargetSkia::SetTransform" set of crashes assosciated with this is the same issue -- I picked out half a dozen random crashes from there, and many are unrelated to printing, so I think there's (at least) two distinct bugs that have the same top frame.

In the meantime, we continue to investigate and try to resolve the printing bug described in Alice's reporting instructions.
I debugged this a bit more (great work on the earlier debugging BTW). This can only happen because we spin the event loop under the e10s printing code (we should stop doing that, see bug 1432806). Because of that we can end up doing things like processing the a11y events while in the middle of recording the printer output that is to be sent to the parent process. That by itself wouldn't be enough to cause this bug, but what appears to be happening is that the a11y code is running in the statically cloned document that we create to print from. I'm not familiar with the a11y code, but it really shouldn't be touching these static documents at all. I tested adding an early return to NotificationController::WillRefresh and that appears to stop the crash. Let's see what the a11y peers think.
Flags: needinfo?(jwatt)
Attached patch patch (obsolete) — Splinter Review
Attachment #8945110 - Flags: review?(surkov.alexander)
(In reply to Jonathan Watt [:jwatt] (needinfo? me) from comment #26)
> bug 14328006

That should be bug 1432806.
(In reply to Jonathan Watt [:jwatt] (needinfo? me) from comment #26)
> I'm not familiar with the a11y code, but it
> really shouldn't be touching these static documents at all. I tested adding
> an early return to NotificationController::WillRefresh and that appears to
> stop the crash. Let's see what the a11y peers think.

if this is indeed nothing the user can interact with, then we should toss out such documents early https://dxr.mozilla.org/mozilla-central/source/accessible/base/DocManager.cpp#474
Thanks! I'll update the patch.
Attached patch patchSplinter Review
Attachment #8945110 - Attachment is obsolete: true
Attachment #8945110 - Flags: review?(surkov.alexander)
Attachment #8945155 - Flags: review?(surkov.alexander)
Attachment #8945155 - Flags: review?(surkov.alexander) → review+
Confirmed that the patch resolves the issue, as originally reported!

Thanks for looking at this :jwatt!
Pushed by jwatt@jwatt.org:
https://hg.mozilla.org/integration/mozilla-inbound/rev/1063efb84fbe
Prevent the a11y code running on static clone (printing) docs. r=surkov
Comment on attachment 8945155 [details] [diff] [review]
patch

Preemptively requesting approval so I don't forget.

Approval Request Comment
[Feature/Bug causing the regression]: bug 1414834
[User impact if declined]: Users with accessibility turned of will be unable to print (they will crash)
[Is this code covered by automated tests?]: only manual testing to my knowledge
[Has the fix been verified in Nightly?]: just landed
[Needs manual test from QE? If yes, steps to reproduce]: see comment 4
[List of other uplifts needed for the feature/fix]: none
[Is the change risky?]: very low risk
[Why is the change risky/not risky?]: it simply turns off accessibility for internal documents that the accessibility code shouldn't be on for
[String changes made/needed]: none
Attachment #8945155 - Attachment description: a11y-crash → patch
Attachment #8945155 - Flags: approval-mozilla-beta?
https://hg.mozilla.org/mozilla-central/rev/1063efb84fbe
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla60
Comment on attachment 8945155 [details] [diff] [review]
patch

Crash fix, should end up in beta 5.
Attachment #8945155 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Flags: qe-verify+
crash reports with this signature are still continuing to come in after the patch has landed in 59.0b5.
should we reopen this bug or get something new on file for this?
Flags: needinfo?(agaynor)
Please open a new one, as I mentioned in https://bugzilla.mozilla.org/show_bug.cgi?id=1426807#c25 I don't think all the crashes in this report are the same as the original one Alice reported.

For whatever bug gets filed, it'd be very helpful to include a regression range.
Flags: needinfo?(agaynor)
ok, will do. unfortunately with the deletion of all crash reports prior to december 25, it's going to be very difficult to come up with a regression range for signatures regressing in the 59 cycle just based on socorro data...
If we have reproducer steps, mozregression to the rescue! If not :-(
looking closer at it, all these crashes with a11y=true in the reports seem to have indeed stopped in 59.0b5.
for the remaining issue i've filed bug 1434762...
I have manged to reproduce the issue described in comment 0 using Friefox 59.0a1 (BuildId:20180103230158).

This issue is no longer reproducible using Firefox 60.0a1 (BuildId:20180209102946) and Firefox 59.0b8 (BuildId:20180208193705) on Windows 10 64bit.
Status: RESOLVED → VERIFIED
Flags: qe-verify+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: