Performance regression with XML Editor in trunk

[su_v]

Files with a rather flat structure and several thousands of objects in single container elements (e.g. top-level layers, or groups), or with a huge number of resource definitions in the <defs> section can take several minutes to open the built-in XML Editor in current trunk.
In current stable (0.48.3.1), the same tests took around max 30 sec until the dialog was open and functional.

Waiting 10 minutes until the dockable XML Editor has opened, and Inkscape unfreezes again, is problematic IMHO, even with very large files.

This issue can also affect the initial loading of such files if the XML Editor was opened last time the session was quit and dialog states are saved across sessions.

It also affects working with multiple files within the same session: if the XML Editor has been opened (and closed) once in the current session, loading large files from within Inkscape later on in the same session is also affected even if the XML Editor does not automatically open in the new document window.

Tested with Inkscape 0.48.3.1 and 0.48+devel r11487 on OS X 10.7.4
( 64bit builds (-O2), compiler: llvm-gcc-4.2 )

[su_v (suv-lp)]

test file 1 (flat structure)

[su_v (suv-lp)]

test file 2 (groups with max. 1444 child elements)

[jazzynico (jazzynico)]

Confirmed on Debian Wheezy, Inkscape trunk revision 11487.

[Alvin Penner (apenner)]

just for curiosity, is the Fill & Stroke dialog loading adversely affected by this?

[jazzynico (jazzynico)]

# inkscape -f 152x152-16-groups-2c.svg --verb=DialogFillStroke --verb=FileClose
and
# inkscape -f 152x152-16-groups-2c.svg --verb=FileClose
take more or less the same amount of time.

[su_v (suv-lp)]

Alvin Penner wrote
> just for curiosity, is the Fill & Stroke dialog loading adversely
> affected by this?

Could you clarify? I don't really understand this question and how it relates to the XML Editor dialog.

Possibly (but I haven't verified yet by testing with archived builds) the internal refactoring of the XML Editor (replacing GtkCTree with GtkTreeView, see bug #903676) is partially responsible for the performance regression when opening the XML Editor if the current file has a huge amount of child objects inside one node of the XML tree (e.g. in a layer, or a group).

IIRC some of the drop-down lists in the Fill&Stroke dialog had to be refactored too to prepare the migration to GTK3 (e.g. replacing the deprecated GtkOptionMenu widget with GtkComboBox - bug #903671, bug #943225) - if you see performance regressions with 'Fill&Stroke', I would propose to file a separate report about it, with sample files and steps to reproduce.

[Alvin Penner (apenner)]

sorry, I guess it is unrelated. I have sometimes seen a lot of activity when monitoring some routines that refresh data when opening the Fill&Stroke, but I guess it is unrelated to this.

[su_v (suv-lp)]

> Possibly (but I haven't verified yet by testing with archived builds)
> the internal refactoring of the XML Editor (replacing GtkCTree with
> GtkTreeView, see bug #903676) is partially responsible for the
> performance regression

Confirmed with archived builds (comparing r11208, r11220 with r11221, with new preferences for each run): r11208 opens the XML Editor in about the same time as current stable (< 40 sec), r11221 OTOH takes ~10 minutes (like current trunk) until the dialog opens and Inkscape is responsive again:

A) compiler: Apple llvm-gcc-4.2

$ rm ~/.config/inkscape/preferences.xml
$ time /Volumes/cyan/src/inkscape/inkscape-repo/mp-test/inst/bin/inkscape-11208-orig 152x152-clones-unlinked-2b.svg --verb=DialogXMLEditor --verb=FileClose

real 0m34.714s
user 0m33.354s
sys 0m0.341s
$ rm ~/.config/inkscape/preferences.xml
$ time /Volumes/cyan/src/inkscape/inkscape-repo/mp-test/inst/bin/inkscape-11221 152x152-clones-unlinked-2b.svg --verb=DialogXMLEditor --verb=FileClose

real 10m15.134s
user 10m13.913s
sys 0m0.857s
$

B) compiler: FSF GCC 4.6.3

$ rm ~/.config/inkscape/preferences.xml
$ time /Volumes/cyan/src/inkscape/inkscape-gcc46-2/inst/bin/inkscape-11220 152x152-clones-unlinked-2b.svg --verb=DialogXMLEditor --verb=FileClose

real 0m38.794s
user 0m35.662s
sys 0m0.542s
$ rm ~/.config/inkscape/preferences.xml
$ time /Volumes/cyan/src/inkscape/inkscape-gcc46-2/inst/bin/inkscape-11221 152x152-clones-unlinked-2b.svg --verb=DialogXMLEditor --verb=FileClose

real 10m5.073s
user 10m2.386s
sys 0m0.761s
$

[su_v (suv-lp)]

@John Smith - subscribing you to this report: any chance you could take a closer look at this performance regression?

[John Smith (john-smithi)]

Committed r11488 - simple performance optimization.
Load time for test files with XML Editor now about 22 sec (r11488) vs 15 sec (0.48.2).

[su_v (suv-lp)]

> Committed r11488 - simple performance optimization.
> Load time for test files with XML Editor now about 22 sec (r11488) vs 15 sec (0.48.2).

Confirmed on OS X 10.7.4 (2.4 GHz Intel Core i5), optimized builds (O2):

Test case:
$ time inkscape -f 152x152-clones-unlinked-2b.svg --verb=DialogXMLEditor --verb=FileClose

Inkscape 0.48.3.1 ~38 sec
Inkscape 0.48+devel r11488 ~58 sec

[su_v (suv-lp)]

Remaining issue: working with multiple files in the same session:

Steps to reproduce:

0) rm -r ~/.config/inkscape
1) launch inkscape (new default doc, empty)
2) draw a rect
3) open and close the XML Editor
4) open '152x152-clones-unlinked-2b.svg' from 'File > Open Recent'
5) close (Ctrl+W) '152x152-clones-unlinked-2b.svg' again
6) close 'New Document 1' too

Expected result (as in stable 0.48.3.1):
Step 4 and step 5 happen without noticeable delay - beyond the time it takes to parse a large vector file.

Actual result (in r11488):
Step 4 and step 5 are each delayed by about the same amount it takes to open the XML Editor if the same file '152x152-clones-unlinked-2b.svg' had been opened in a separate process. The delay does not happen if step 3 is omitted.

[John Smith (john-smithi)]

Committed r11495 - to improve load time on large documents when XML Editor is reloaded.

[John Smith (john-smithi)]

> Remaining issue: working with multiple files in the same session:

I think this is mainly caused by the XML Editor now being a dockable dialog (bug #940715).

When you "close" any dockable dialog, it does not get destroyed, its just visibly hidden and it sticks around in memory until the last inkscape window is closed.
You can test this by
1) opening a large test file
2) open the XML Editor - it will be slow
3) closing and re-opening the XML Editor will now be fast - since its still in memory.

Not only is a "closed" dockable dialog hidden, but its also considered *floating*. So a "closed" dockable dialog is functionally equivalent to an open and floating dialog. A "iconified" dialog is also considered floating and suffers the same problems.

This is the core of the problem since when you switch windows (or open a new doc etc) a floating dialog gets a signal to reload the currently focused document.

You can test this by
1) opening a large test file
2) and open a smaller test file
3) Float the XML Editor
4) Switch focus between the 2 windows - should see a delay when focusing on the large test file only.
5) Now "close" or "iconify" the XML Editor - should see the same delay as in 4) when switching windows
6) Now dock the XML Editor - should see no delay switching windows

So the possible solutions include:
a) Have dockable dialogs be properly destroyed when then are "closed"
b) Have dockable dialogs not be considered floating when they are hidden or iconified (libgdl change)
c) Have dialogs only receive the "desktop change" signal if they are visible - then add logic to check the document when the visibility status is changed
d) Leave as-is

[su_v (suv-lp)]

On 10/09/2012 06:02, John Smith wrote:
>> Performance regression with XML Editor in trunk
> Perhaps the 0.49 miletone can be removed , as not sure anything can
> be done with this, since its mainly an issue with the underlying
> docking dialog.

I do recall having noticed similar regressions with the 'Layers…' dialog (unexpected and noticeable delay when working with multiple documents opened from within the same inkscape process) with files which have lots of (nested) layers, which IIRC didn't happen with current stable versions.

If time permits, I will revisit the issue and - if consistently reproducible - provide more details (including a test case), else I'll remove the milestone before 'Frost' sets (October 5, 2012) [1].

---
[1] http://article.gmane.org/gmane.comp.graphics.inkscape.translator/1251

[su_v (suv-lp)]

Removing milestone based on comment #15.