Certain clipping paths in documents with viewBox cause infinite update-redraw loops

[David Mathog]

In revision 13047 the attached PDF test file is somehow toxic for Inkscape. The symptoms vary a little, but in general what happens is that when this file is opened large large swaths of the GUI drop out and the window stops responding. This happened on both linux and windows. The symptoms were more immediate on linux. On Windows the GUI appeared to be intact, but then the pull down menus stopped working, and eventually the window locked there too.

[David Mathog (mathog)]

This is the source svg file used to make the toxic pdf via "save as" to PDF. The text decoration is lost on export, as expected, since implementing that is what I was looking into when this problem was discovered. The other features of the (simple) file make it into the PDF, and they look normal in the one PDF viewer I used to open the file. (PDF X-Change Viewer).

[su_v (suv-lp)]

Symptoms after PDF import vary with OS X builds, but it is for example impossible to save a copy of the opened PDF as SVG for further investigation, because Inkscape hangs while populating the file dialog with entries.

Tests with archived builds:
- not reproduced with rev <= 12571
- reproduced with rev >= 12576
<http://bazaar.launchpad.net/~inkscape.dev/inkscape/trunk/changes/12576>

Possibly related to viewBox changes (12575), and the pattern-filled text.

[su_v (suv-lp)]

> - not reproduced with rev <= 12571
> (…)
> Possibly related to viewBox changes (12575)

Note that with rev >= 12557, the scale of the imported PDF file was incorrect (bug #1228660), but otherwise works ok (even with the pattern-filled text in the sample PDF file here). Revision 12575 / 12576 fixed the viebox for import of PDF and other formats.

[su_v (suv-lp)]

Attaching SVG version of the PDF file saved with r12556 (opens ok with current trunk).

[su_v (suv-lp)]

How to produce a crash with the attached PDF file:

1) launch trunk rev >= 12575/12576 (default prefs, default new doc)
2) draw a rect to dirty the current document
3) open the PDF file (from within current inkscape process)
4) after loading of the PDF file is complete, close the window again with 'Ctrl+W'
--> crash (full bt with r13055 attached).

Backtrace with regular build r12576:

Program received signal EXC_BAD_ACCESS, Could not access memory.
Reason: KERN_INVALID_ADDRESS at address: 0x0000000000000048
0x000000010003da6f in SPDocument::getResourceList ()
(gdb) bt
#0 0x000000010003da6f in SPDocument::getResourceList ()
#1 0x0000000100558c4d in Inkscape::UI::Dialogs::recalcSwatchContents ()
#2 0x0000000100559e7e in Inkscape::UI::Dialogs::SwatchesPanel::handleDefsModified ()
#3 0x00000001005594f3 in Inkscape::UI::Dialogs::DocTrack::handleTimerCB ()
#4 0x0000000100006e27 in sigc::internal::slot_call0<sigc::pointer_functor0<bool>, bool>::call_it ()
#5 0x0000000101e4d2e3 in (anonymous namespace)::glibmm_source_callback ()
#6 0x00000001030f1b68 in g_timeout_dispatch ()
#7 0x00000001030f44cc in g_main_context_dispatch ()
#8 0x00000001030f47ce in g_main_context_iterate ()
#9 0x00000001030f4a53 in g_main_loop_run ()
#10 0x0000000101771181 in gtk_main ()
#11 0x0000000100006569 in sp_main_gui ()
#12 0x00000001000023c4 in start ()

[David Mathog (mathog)]

Note also that if "top" is running in another window when the toxic file opens the CPU usage never settles down. Normally in Inkscape when nothing is happening the CPU usage drops to something small, <1% typically. Here it stayed above 70%.

Finally managed to get a controlled exit from within valgrind by:

valgrind -v --leak-check=yes --leak-resolution=high --num-callers=15 --show-reachable=yes --suppressions=./wcslen_sse2.supp src/inkscape --file /tmp/td_test1.pdf >/tmp/vgA.log 2>&1

then when it finally opened the main window, click once on a bare patch near the bottom and enter ^Q. There are a variety of access violations and "conditional jump or move depends on uninitialized values(s)". Relevant part of the valgrind log attached. That is followed by a typical insanely long list of memory warnings - too much stuff in there to figure out if there is anything new related to this bug.

[David Mathog (mathog)]

The attached patch gets rid of the memory problems in svg_builder.cpp that are associated with the text input. It wasn't handling the case properly where the input text was a single character.

Unfortunately those memory errors were not the problem. Valgrind run on this patched version opening the toxic PDF and the equivalent SVG source narrowed the issue down to the regions indicated in the next attachment. Assuming those uses of uninitialized variables are in fact the problem. Notably the first of them goes through the expected place, NRStyle::prepareFill in nr-style.cpp. That makes it look the PDF parser is creating a pattern that is itself toxic, since if the PDF file text is just solid, there is no problem opening it. If the pattern is toxic, then it is probably toxic no matter what it fills. Testing that...

1. open inkscape
2. create a rectangle
3. fill it with packed circles, no border
4. Save as... to PDF
5. Open that PDF file

Result - inkscape goes nuts.

[David Mathog (mathog)]

Part of valgrind output implicating use of uninitialized variables in control statements. This is just the two regions that are only triggered by the toxic input in the PDF form of the test case, but not by the input of the SVG form of the test case.

[David Mathog (mathog)]

This is another toxic PDF, again with packed circles for the fill, but this time in a rectangle.

[David Mathog (mathog)]

Ugh, this is looking worse and worse. Converted a toxic PDF to plain svg using:

 src/inkscape -l /tmp/packed_circles_in_rect_plain.svg --file /tmp/packed_circles_in_rect.pdf

and the resultant svg is also toxic (but somewhat less so). Open it in Inkscape and CPU usage sticks at 35% and parts of the GUI do not redraw. This was also the case when the original fill was 1:1 stripes.

So the PDF input is a red herring, or at least partially a red herring, since the rest of inkscape is apparently responsible for most of the problem when this information is handled, even straight from an SVG.

[David Mathog (mathog)]

I have narrowed the problem down to a couple of lines in one of the toxic SVGs, attached.

If this

       <g id="g26"
           clip-path="url(#clipPath16)">
          <path
               id="path30"
               style="fill:#000000;fill-opacity:1;fill-rule:nonzero;stroke:none"
               d="m 0,150 100,0 0,-200 -100,0 0,200 z" />
        </g>

is changed to just

          <path
               id="path30"
               style="fill:#000000;fill-opacity:1;fill-rule:nonzero;stroke:none"
               d="m 0,150 100,0 0,-200 -100,0 0,200 z" />

then the problem goes away. So there appears to be an issue with clipping, probably an infinite loop.
 Using gdb and hitting control-C while stuck after loading the toxic one, bt always showed this:

#0 0x00132416 in __kernel_vsyscall ()
#1 0x019da460 in __GI___poll (fds=0xbfffeed8, nfds=1, timeout=-1) at ../sysdeps/unix/sysv/linux/poll.c:87
#2 0x01d28120 in ?? () from /usr/lib/i386-linux-gnu/libxcb.so.1
#3 0x01d29a60 in ?? () from /usr/lib/i386-linux-gnu/libxcb.so.1
#4 0x01d29d17 in xcb_wait_for_reply () from /usr/lib/i386-linux-gnu/libxcb.so.1
#5 0x014b1682 in _XReply () from /usr/lib/i386-linux-gnu/libX11.so.6
#6 0x014a6d23 in XQueryPointer () from /usr/lib/i386-linux-gnu/libX11.so.6
#7 0x00a10199 in ?? () from /usr/lib/i386-linux-gnu/libgdk-x11-2.0.so.0
#8 0x009bb0ae in ?? () from /usr/lib/i386-linux-gnu/libgdk-x11-2.0.so.0
#9 0x009deba7 in gdk_window_get_pointer () from /usr/lib/i386-linux-gnu/libgdk-x11-2.0.so.0
#10 0x08304765 in SPCanvasImpl::sp_canvas_paint_rect (canvas=0x9fd7040, xx0=32, yy0=-480, xx1=176, yy1=-384) at display/sp-canvas.cpp:2103
#11 0x08304d36 in SPCanvasImpl::paint (canvas=0x9fd7040) at display/sp-canvas.cpp:2260
#12 0x08304e67 in SPCanvasImpl::do_update (canvas=0x9fd7040) at display/sp-canvas.cpp:2295
#13 0x08304ed8 in SPCanvasImpl::idle_handler (data=0x9fd7040) at display/sp-canvas.cpp:2311
#14 0x009b8f88 in ?? () from /usr/lib/i386-linux-gnu/libgdk-x11-2.0.so.0
#15 0x01315810 in ?? () from /lib/i386-linux-gnu/libglib-2.0.so.0
#16 0x01317d46 in g_main_context_dispatch () from /lib/i386-linux-gnu/libglib-2.0.so.0
#17 0x013180e5 in ?? () from /lib/i386-linux-gnu/libglib-2.0.so.0
#18 0x0131852b in g_main_loop_run () from /lib/i386-linux-gnu/libglib-2.0.so.0
#19 0x00671b8f in gtk_main () from /usr/lib/i386-linux-gnu/libgtk-x11-2.0.so.0
#20 0x00302194 in Gtk::Main::run_impl() () from /usr/lib/i386-linux-gnu/libgtkmm-2.4.so.1
#21 0x00302bcf in Gtk::Main::run() () from /usr/lib/i386-linux-gnu/libgtkmm-2.4.so.1
#22 0x08087888 in sp_main_gui (argc=1, argv=0xbffff6d4) at main.cpp:1097
#23 0x08086ef0 in main (argc=1, argv=0xbffff6d4) at main.cpp:812

When inkscape was running normally with a nontoxic version of the same image this was never seen. Those always looked like this:

#0 0x00132416 in __kernel_vsyscall ()
#1 0x019da460 in __GI___poll (fds=0xb7a97e0, nfds=3, timeout=33) at ../sysdeps/unix/sysv/linux/poll.c:87
#2 0x01325a3b in g_poll () from /lib/i386-linux-gnu/libglib-2.0.so.0
#3 0x0131806e in ?? () from /lib/i386-linux-gnu/libglib-2.0.so.0
#4 0x0131852b in g_main_loop_run () from /lib/i386-linux-gnu/libglib-2.0.so.0
#5 0x00671b8f in gtk_main () fro...

[su_v (suv-lp)]

On 2014-02-25 22:57 +0100, David Mathog wrote:
> Converted a toxic PDF to plain svg using:
>
> src/inkscape -l /tmp/packed_circles_in_rect_plain.svg --file /tmp/packed_circles_in_rect.pdf

I repeated this conversion with an archived build on OS X which based on earlier tests does not produce "toxic" SVG files when loading the "toxic" PDF file (see attached).

The only difference between my file and the one attached by David in comment #11 is a single line (see also comment #3): the "toxic" SVG file contains a viewBox attribute, the one created with the older rev 12556 does not, and loads fine in current trunk.

$ diff -u 1284391-packed_circles_in_rect_plain-r12556.svg 1284391-packed_circles_in_rect_plain.svg
--- 1284391-packed_circles_in_rect_plain-r12556.svg 2014-02-26 00:03:32.000000000 +0100
+++ 1284391-packed_circles_in_rect_plain.svg 2014-02-25 23:55:00.000000000 +0100
@@ -11,6 +11,7 @@
    version="1.1"
    width="744.09448"
    height="1052.3622"
+ viewBox="0 0 744.09448 1052.3622"
    id="svg2"
    xml:space="preserve"><metadata
      id="metadata8"><rdf:RDF><cc:Work

[David Mathog (mathog)]

Agreed, removing the viewbox also mitigates the problem.

I tried moving the clipping from around the pattern into the rectangle which is filled (after changing the values to match that rectangle) and there were no Inkscape issues when that was opened.

So it seems that clipping causes problems when:

1. viewbox is present

AND

2. clipping is applied as part of a <g> around <pattern>

r12575 modifies pdf-input.cpp by turning on the viewbox. I it looks like all the changes at r12575 only turn on the viewbox the same way in various other modules. It appears that r12575 exposed the issue, but it didn't cause it.

With the revisions you have on hand, can you narrow down the revision range where the (toxic) SVG files start to cause inkscape problems? The only other one I have is 11679, and stripes_in_rect_plain.svg is toxic there.

[su_v (suv-lp)]

Oldest archived build on my current laptop is r10795, and it can't handle the "toxic" SVG file either.

Clip-paths in patterns have been problematic with the old renderer too (see e.g. bug #168014, bug #955141).

[Johan Engelen (johanengelen)]

Regarding the crash from comment #6:
What happens is that the SPDocument is deleted, and then Inkscape::UI::Dialogs::recalcSwatchContents calls getResourceList on a deleted document (so that's very very bad!!!). The crash happens because the deleted SPDocument has member variable priv set to NULL. So a check for priv==nullptr fixes the crash, but still, it is very bad that getResourceList is called for a deleted SPDoc...

[Johan Engelen (johanengelen)]

Fixed the crash of comment #6 in r13068!

[Johan Engelen (johanengelen)]

Unfortunately, the crash is not fixed at all... The swatches dialog code is seriously bugged. For example, ~DocTrack is never called.......

[David Mathog (mathog)]

This is the smallest/simplest test case I have been able to construct.

[David Mathog (mathog)]

The problem is apparently that the clip (in the pattern) is marking some object(s) as modified, and the object(s) is(are) marking the clip as modified, in each cycle, when nothing has changed one iota. Result, infinite loop. By dropping in DEBUG lines in the likely places in sp-canvas.cpp (no prefix) and sp-clippath.cpp (entries with SPClipPath::) this much of the loop has been mapped out (c-> is canvas->, i-> is item->):

DEBUG idle_handler TOP
DEBUG do_update TOP c->need_update 1
DEBUG sp_canvas_item_invoke_update TOP item 0xa362800 i->need_update 1
DEBUG sp_canvas_item_invoke_update TOP item 0xa10bbc8 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa10bbc8 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa3628a8 i->need_update 1
DEBUG sp_canvas_item_invoke_update TOP item 0xa39d948 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa39d948 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa39da30 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa39da30 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa39db18 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa39db18 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa3a2078 i->need_update 1
DEBUG requestRedraw window 0,-236 1,-235 need_update 1 need_redraw 1
DEBUG dirty because of clip
DEBUG sp_canvas_dirty_rect SETTING c->need_redraw
DEBUG sp_canvas_item_invoke_update BOT item 0xa3a2078 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa362950 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa362950 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa3629f8 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa3629f8 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa362aa0 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa362aa0 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa362b48 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa362b48 i->need_update 0
DEBUG sp_canvas_item_invoke_update TOP item 0xa362bf0 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa362bf0 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa3628a8 i->need_update 0
DEBUG sp_canvas_item_invoke_update BOT item 0xa362800 i->need_update 0
DEBUG do_update MID UNSETTING c->need_update
DEBUG paint TOP c->need_update 0 c->need_redraw 1
DEBUG dirty i 0 j -15
DEBUG sp_canvas_paint_rect TOP c->need_update 0
DEBUG sp_canvas_paint_rect_internal TOP
DEBUG sp_canvas_paint_single_buffer TOP
DEBUG SPClipPath::show
DEBUG SPClipPath::hide
DEBUG UNSETTING c->need_redraw
DEBUG paint BOT c->need_update 0 c->need_redraw 0
DEBUG SPClipPath::update
DEBUG requestRedraw window 0,-236 1,-235 need_update 0 need_redraw 0
DEBUG dirty because of clip
DEBUG sp_canvas_dirty_rect SETTING c->need_redraw
DEBUG sp_canvas_item_request_update TOP item 0xa3a2078 i->need_update 0
DEBUG before sp_canvas_item_request_update 3 item 0xa3628a8
DEBUG sp_canvas_item_request_update TOP item 0xa3628a8 i->need_update 0
DEBUG before sp_canvas_item_request_update 3 item 0xa362800
DEBUG sp_canvas_item_request_update TOP item 0x...

[David Mathog (mathog)]

This patch quashes the infinite loop. It has two parts.

1. A style change to sp_document_idle_handler() in documents.cpp, which originally had two exit points for no good reason. I'm adding it here as it is as good a place as any.

2. The second comments out what appears to be an extraneous call to requestDisplayUpdate on the clipping path in sp-item.cpp. This was setting the SP_OBJECT_MODIFIED_FLAG on the clip object, which then propagated all the way back up to the root where the SP_OBJECT_CHILD_MODIFIED_FLAG was triggering endless rounds of redraws. The clipping test cases I tried (previous post) work fine with this line commented out. However, I have no confidence that this is true all the time. It may be that the true problem is somewhere above this, in code that should have stopped that propagation.

Please note that a few lines down from this one finds

            mask->requestDisplayUpdate(SP_OBJECT_MODIFIED_FLAG);

which is the same construct for a "mask" object. Based on code symmetry it seems reasonable to expect that an infinite loop might result there too if a mask is used in a pattern. However, I don't know how to construct that test case, nor even if it is legal to have a mask in a pattern.

I cannot explain why setting ViewBox enabled this bug.

[David Mathog (mathog)]

The attached file has a bunch of mask examples. As far as I can tell Inkscape handles it just the same whether or not the

            mask->requestDisplayUpdate(SP_OBJECT_MODIFIED_FLAG);

line has been commented out in the build. I was able to drag things around, cut and paste (subject to the inability at present to cut and paste gradients). There is a different problem with the test case (bug #1286407) but those are not related to the presence or absence of this line.

[Krzysztof Kosinski (tweenk)]

Patch from comment #23 does not seem to fix the problem for me.

The actual underlying cause might be that rendering a pattern internally involves calling invoke_show in the wrong phase. Normally, it should be called in response to SP tree changes (update() phase in the SP tree), but for patterns it is called while rendering (update() phase in the display tree).

[David Mathog (mathog)]

re 25

At present I all patterns are broken on my linux test system (with r13117, bug #1288489). However, even in that broken state applying the patch killed the infinite loop when "minimal_bad.svg" was loaded, so that even though no patterns were visible, the file loaded without hanging inkscape in a loop.

Please tell us exactly what you did in your test and what you saw.

[Krzysztof Kosinski (tweenk)]

I loaded stripes_in_rect_plain.svg; the pattern was blank and showed 100% CPU usage. I will re-test with r13120 where that bug should be fixed.

[David Mathog (mathog)]

stripes_in_rect_plain.svg worked for me with the patch and r13120. Note that normally if the mouse pointer is anywhere over the Inkscape window "top" usually shows 1 or 2% cpu, depending on where it is hovering. Load one of the toxic files and place the pointer off the Inkscape window and this goes to zero when the patch is applied, but will be a significant number (15%, 30%?) otherwise, even though the mouse is out of the picture (so to speak).

[su_v (suv-lp)]

Retesting on OS X 10.7.5 with 0.91pre2 r13645, 0.91+devel 13729 as well as with archived trunk builds:

1) Slow GUI responsiveness, high CPU usage with
   td_test1.pdf (comment #1),
   packed_circles_in_rect_plain.svg (comment #11),
   stripes_in_rect_plain.svg (comment #12),
   minimal_bad.svg (comment #12),
   clip-tests.svg (comment #22):
   - reproduced with rev <= 13580
   - not reproduced with rev >= 13581
   Seems fixed with the changes in r13581:
   http://bazaar.launchpad.net/~inkscape.dev/inkscape/trunk/revision/13581

2) crash with td_test1.pdf (comment #6)
   - reproduced with rev <= 13090
   - not reproduced with rev >= 13095;
   Likely fixed with the changes in revision 13092 or 13094/13095:
   http://bazaar.launchpad.net/~inkscape.dev/inkscape/trunk/changes/13095

Proposing to remove 'blocker' tag and closing as 'Fix Committed' with milestone 0.91 if confirmed by at least one other user on a different OS/platform.

[ScislaC (scislac)]

Tested with 0.91.x r13647 and trunk r13731 on Ubuntu 14.10 and can't reproduce in either.