1259032 - Printing from PDF Viewer (pdf.js) seems to leak memory.

Status: NEW

(Core :: Printing: Output, defect)

Description

[Bob Owen (:bobowen)]

Breaking this out from bug 1258609 as it seems to be a somewhat different issue from the printing via parent one.

I was testing with a pdf version of https://html.spec.whatwg.org/multipage/introduction.html, which was 17 pages long.

Each print using PDF Viewer seems to cause an extra 7 or 8 MB of memory use, which doesn't get reclaimed even when the tab is closed.

This happens in e10s and non-e10s, Release and Nightly.
Only tested on Window 7 64-bit with Firefox 32-bit.

Example diff from about:memory before and after a print (1 level down only):
Explicit Allocations

5.71 MB (100.0%) -- explicit
├──7.34 MB (128.43%) ── heap-unclassified
├──-0.97 MB (-16.93%) ++ heap-overhead
├──-0.23 MB (-4.04%) ++ js-non-window
├──-0.21 MB (-3.64%) ── layout/rule-processor-cache
├──-0.11 MB (-1.85%) ++ storage/sqlite
├──-0.08 MB (-1.47%) ++ (7 tiny)
└──-0.03 MB (-0.51%) ++ window-objects

Comment 1

[Timothy Nikkel (:tnikkel)]

A good first step would be to use a DMD build to find out whats in the heap-unclassified.

Comment 2

[Eric Rahm [:erahm]]

I'll follow up with a DMD run.

Comment 3

[Eric Rahm [:erahm]]

Attachment: DMD, memory reports, and diff

Results after loading the page, doing a DMD report ('before-printing'), printing, doing a DMD report ('after-printing'). A DMD diff is included as well, the top unreported stacks are clearly printing related:

> Unreported {
>   6 blocks in heap block record 1 of 954
>   3,858,432 bytes (3,844,982 requested / 13,450 slop)
>   Individual block sizes: 843,776; 839,680; 774,144; 712,704; 565,248; 122,880
>   43.18% of the heap (43.18% cumulative)
>   42.09% of unreported (42.09% cumulative)
>   Allocated at {
>     #01: moz_xmalloc (c:\dev\mozilla-central\memory\mozalloc\mozalloc.cpp:83)
>     #02: std::_Allocate (c:\program files (x86)\microsoft visual studio 14.0\vc\include\xmemory0:69)
>     #03: std::vector<char,std::allocator<char> >::_Reallocate (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1625)
>     #04: std::vector<unsigned char,std::allocator<unsigned char> >::_Reserve (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1654)
>     #05: std::vector<unsigned char,std::allocator<unsigned char> >::resize (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1143)
>     #06: mozilla::gfx::DWriteFontFileStream::DWriteFontFileStream (c:\dev\mozilla-central\gfx\2d\nativefontresourcedwrite.cpp:173)
>     #07: mozilla::gfx::NativeFontResourceDWrite::Create (c:\dev\mozilla-central\gfx\2d\nativefontresourcedwrite.cpp:232)
>     #08: mozilla::gfx::Factory::CreateNativeFontResource (c:\dev\mozilla-central\gfx\2d\factory.cpp:542)
>     #09: mozilla::gfx::RecordedFontData::PlayEvent (c:\dev\mozilla-central\gfx\2d\recordedevent.cpp:1471)
>     #10: mozilla::layout::PrintTranslator::TranslateRecording (c:\dev\mozilla-central\layout\printing\printtranslator.cpp:61)
>     #11: mozilla::layout::RemotePrintJobParent::PrintPage (c:\dev\mozilla-central\layout\printing\ipc\remoteprintjobparent.cpp:116)
>     #12: mozilla::layout::RemotePrintJobParent::RecvProcessPage (c:\dev\mozilla-central\layout\printing\ipc\remoteprintjobparent.cpp:88)
>     #13: mozilla::layout::PRemotePrintJobParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\premoteprintjobparent.cpp:298)
>     #14: mozilla::dom::PContentParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\pcontentparent.cpp:3806)
>     #15: mozilla::ipc::MessageChannel::DispatchAsyncMessage (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1631)
>     #16: mozilla::ipc::MessageChannel::DispatchMessageW (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1571)
>     #17: mozilla::ipc::MessageChannel::OnMaybeDequeueOne (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1537)
>     #18: MessageLoop::RunTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:365)
>     #19: MessageLoop::DeferOrRunPendingTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:375)
>     #20: MessageLoop::DoWork (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:459)
>     #21: mozilla::ipc::DoWorkRunnable::Run (c:\dev\mozilla-central\ipc\glue\messagepump.cpp:223)
>     #22: nsThread::ProcessNextEvent (c:\dev\mozilla-central\xpcom\threads\nsthread.cpp:994)
>     #23: NS_ProcessNextEvent (c:\dev\mozilla-central\xpcom\glue\nsthreadutils.cpp:297)
>     #24: mozilla::ipc::MessagePump::Run (c:\dev\mozilla-central\ipc\glue\messagepump.cpp:97)
>   }
> }
> 
> Unreported {
>   4 blocks in heap block record 2 of 954
>   2,686,976 bytes (2,679,804 requested / 7,172 slop)
>   Individual block sizes: 753,664; 712,704; 663,552; 557,056
>   30.07% of the heap (73.25% cumulative)
>   29.31% of unreported (71.40% cumulative)
>   Allocated at {
>     #01: moz_xmalloc (c:\dev\mozilla-central\memory\mozalloc\mozalloc.cpp:83)
>     #02: std::_Allocate (c:\program files (x86)\microsoft visual studio 14.0\vc\include\xmemory0:69)
>     #03: std::vector<char,std::allocator<char> >::_Reallocate (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1625)
>     #04: std::vector<unsigned char,std::allocator<unsigned char> >::_Reserve (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1654)
>     #05: std::vector<unsigned char,std::allocator<unsigned char> >::resize (c:\program files (x86)\microsoft visual studio 14.0\vc\include\vector:1143)
>     #06: mozilla::gfx::DWriteFontFileStream::DWriteFontFileStream (c:\dev\mozilla-central\gfx\2d\nativefontresourcedwrite.cpp:173)
>     #07: mozilla::gfx::NativeFontResourceDWrite::Create (c:\dev\mozilla-central\gfx\2d\nativefontresourcedwrite.cpp:232)
>     #08: mozilla::gfx::Factory::CreateNativeFontResource (c:\dev\mozilla-central\gfx\2d\factory.cpp:542)
>     #09: mozilla::gfx::RecordedFontData::PlayEvent (c:\dev\mozilla-central\gfx\2d\recordedevent.cpp:1471)
>     #10: mozilla::layout::PrintTranslator::TranslateRecording (c:\dev\mozilla-central\layout\printing\printtranslator.cpp:61)
>     #11: mozilla::layout::RemotePrintJobParent::PrintPage (c:\dev\mozilla-central\layout\printing\ipc\remoteprintjobparent.cpp:116)
>     #12: mozilla::layout::RemotePrintJobParent::RecvProcessPage (c:\dev\mozilla-central\layout\printing\ipc\remoteprintjobparent.cpp:88)
>     #13: mozilla::layout::PRemotePrintJobParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\premoteprintjobparent.cpp:298)
>     #14: mozilla::dom::PContentParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\pcontentparent.cpp:3806)
>     #15: mozilla::ipc::MessageChannel::DispatchAsyncMessage (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1631)
>     #16: mozilla::ipc::MessageChannel::DispatchMessageW (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1571)
>     #17: mozilla::ipc::MessageChannel::OnMaybeDequeueOne (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1537)
>     #18: MessageLoop::RunTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:365)
>     #19: MessageLoop::DeferOrRunPendingTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:375)
>     #20: MessageLoop::DoWork (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:459)
>     #21: mozilla::ipc::DoWorkRunnable::Run (c:\dev\mozilla-central\ipc\glue\messagepump.cpp:223)
>     #22: nsThread::ProcessNextEvent (c:\dev\mozilla-central\xpcom\threads\nsthread.cpp:994)
>     #23: NS_ProcessNextEvent (c:\dev\mozilla-central\xpcom\glue\nsthreadutils.cpp:297)
>     #24: mozilla::ipc::MessagePump::Run (c:\dev\mozilla-central\ipc\glue\messagepump.cpp:129)
>   }
> }
> 
> Unreported {
>   23,127 blocks in heap block record 3 of 954
>   485,632 bytes (419,707 requested / 65,925 slop)
>   Individual block sizes: 1,024 x 37; -512; 496; 480 x 3; -416; 400; 384; 368; 352 x 3; 320; 304 x 56; 288 x 2; 272 x 5; 256 x 18; -224 x 5; 208 x 3; -192 x 104; 176 x 154; 160 x 5; 144 x 936; 128 x 131; -112 x 42; 96 x 176; 80 x 150; 64 x 328; 48 x 324; 32 x 523; 16 x 2,601; 8 x 17,820
>   5.43% of the heap (78.69% cumulative)
>   5.30% of unreported (76.70% cumulative)
>   Allocated at {
>     #01: (no stack trace recorded due to --stacks=partial)
>   }
> }
> 
> Unreported {
>   474 blocks in heap block record 4 of 954
>   485,376 bytes (257,856 requested / 227,520 slop)
>   Individual block sizes: 1,024 x 474
>   5.43% of the heap (84.12% cumulative)
>   5.30% of unreported (82.00% cumulative)
>   Allocated at {
>     #01: _cairo_path_fixed_create (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-path-fixed.c:336)
>     #02: _cairo_win32_scaled_font_glyph_init (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-win32-font.c:1386)
>     #03: _cairo_scaled_glyph_lookup (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-scaled-font.c:2813)
>     #04: _cairo_scaled_font_subsets_map_glyph (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-scaled-font-subsets.c:738)
>     #05: _cairo_win32_printing_surface_emit_win32_glyphs (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-win32-printing-surface.c:1534)
>     #06: _cairo_win32_printing_surface_show_glyphs (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-win32-printing-surface.c:1686)
>     #07: _cairo_surface_show_text_glyphs (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-surface.c:2782)
>     #08: _cairo_surface_wrapper_show_text_glyphs (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-surface-wrapper.c:625)
>     #09: _cairo_recording_surface_replay_internal (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-recording-surface.c:961)
>     #10: _cairo_recording_surface_replay_region (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-recording-surface.c:1039)
>     #11: _paint_page (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-paginated-surface.c:363)
>     #12: _cairo_paginated_surface_show_page (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-paginated-surface.c:466)
>     #13: _moz_cairo_surface_show_page (c:\dev\mozilla-central\gfx\cairo\cairo\src\cairo-surface.c:2540)
>     #14: gfxWindowsSurface::EndPage (c:\dev\mozilla-central\gfx\thebes\gfxwindowssurface.cpp:300)
>     #15: mozilla::layout::RemotePrintJobParent::RecvProcessPage (c:\dev\mozilla-central\layout\printing\ipc\remoteprintjobparent.cpp:88)
>     #16: mozilla::layout::PRemotePrintJobParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\premoteprintjobparent.cpp:298)
>     #17: mozilla::dom::PContentParent::OnMessageReceived (c:\dev\mozilla-central\obj-i686-pc-mingw32\ipc\ipdl\pcontentparent.cpp:3806)
>     #18: mozilla::ipc::MessageChannel::DispatchAsyncMessage (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1631)
>     #19: mozilla::ipc::MessageChannel::DispatchMessageW (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1571)
>     #20: mozilla::ipc::MessageChannel::OnMaybeDequeueOne (c:\dev\mozilla-central\ipc\glue\messagechannel.cpp:1537)
>     #21: MessageLoop::RunTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:365)
>     #22: MessageLoop::DeferOrRunPendingTask (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:375)
>     #23: MessageLoop::DoWork (c:\dev\mozilla-central\ipc\chromium\src\base\message_loop.cc:459)
>     #24: mozilla::ipc::DoWorkRunnable::Run (c:\dev\mozilla-central\ipc\glue\messagepump.cpp:223)
>   }
> }

Comment 4

[Bob Owen (:bobowen)]

(In reply to Eric Rahm [:erahm] from comment #3)
> Created attachment 8737296 [details]
> DMD, memory reports, and diff
> 
> Results after loading the page, doing a DMD report ('before-printing'),
> printing, doing a DMD report ('after-printing'). A DMD diff is included as
> well, the top unreported stacks are clearly printing related:

Looks like this was run on Nightly with e10s on and print via parent enabled (the default).

Those RemotePrintJobParent::RecvProcessPage calls are the print being played back in the parent.
That's a bit of a different problem, with large memory use because of the print getting recorded as a series of images (bug 1258609). As I mentioned in that bug the memory does seem to be getting released.

For this bug the easiest thing is to run with e10s turned off (or set print.print_via_parent=false, but then the memory issue is in the child).

Comment 5

[Eric Rahm [:erahm]]

Attachment: dmd-after-printing-and-minimizing.tx

With e10s disabled, printed, minimized memory usage, took dmd snapshot.

Comment 6

[Timothy Nikkel (:tnikkel)]

(In reply to Eric Rahm [:erahm] from comment #5)
> Created attachment 8737391 [details]
> dmd-after-printing-and-minimizing.tx
> 
> With e10s disabled, printed, minimized memory usage, took dmd snapshot.

The first entry is image related, and there are a few more. I wonder why doesn't it go away after printing and minimizing memory usage. I guess the same question applies to everything else in the report.

When printing, we create static requests (or frozen images) to print the first frame of animated images. It looks like these don't get added to any imgLoader. We measure image measure use by walking the list of images in every existing imgLoader. So that's likely how they end up unreported.