Re: [xml] performance of parsing docbook with xincludes

Seems that the list does not like attachements, so resensing with links

On 05/14/2018 12:19 PM, Nick Wellnhofer wrote:
On 13/05/2018 20:54, Stefan Sauer wrote:
Lets look at some numbers using glib

cd glib/docs/reference/glib
xmllint --timing --xinclude --noout glib-docs.xml
Parsing took 0 ms
Xinclude processing took 4560 ms
Freeing took 91 ms

Any idea how I can get more breakdown of whats happening in  'Xinclude

It seems that "XInclude processing" also contains the time needed to
parse the included documents, so maybe the XIncludes aren't the issue
at all (glib-docs.xml is a small document including several larger
ones). Can you save glib-docs.xml after processing XIncludes and check
whether parsing the consolidated document is considerably faster?

$ xmllint --timing --xinclude glib-docs.xml >glib-full.xml

Parsing took 0 ms
Xinclude processing took 4726 ms
Saving took 85 ms
Freeing took 104 ms

$ xmllint --timing --noout glib-full.xml

Parsing took 151 ms
Freeing took 14 ms

$ ls -alh glib-full.xml

-rw-r--r-- 1 ensonic users 6.8M May 14 12:42 glib-full.xml

Parsing the consolidated doc is a magnitude faster. Thanks for
suggesting this test.

$ xtime sh -c 'find . -name "*.xml" | grep -v version.xml | xargs xmllint --noout'
0.40u 0.04s 0.44r 70296kB sh -c find . -name "*.xml" | grep -v version.xml | xargs xmllint --noout

Even parsing all files like this is >10 times faster.

Running with "perf record -g -- xmllint --timing --xinclude --noout
glib-docs.xml" gets me such a report.

+   17.15%    16.69%  xmllint        [.] _int_malloc
+   11.93%    11.87%  xmllint        [.]
+    9.01%     8.97%  xmllint    [.] xmlDictLookup
+    7.15%     0.00%  xmllint          [.]
+    6.25%     6.21%  xmllint    [.] xmlHashAddEntry3
+    6.22%     0.00%  xmllint    [.]
+    6.22%     0.00%  xmllint  [unknown]           [.]
+    3.95%     3.94%  xmllint    [.] xmlHashLookup2
      3.72%     3.70%  xmllint        [.] _int_free
+    3.28%     0.00%  xmllint  [unknown]           [.] 0000000000000000
+    3.06%     3.04%  xmllint    [.]
+    2.96%     2.91%  xmllint        [.] free

The callgraph based reports (perf report -g or -G) are usually more
here is a full perf.log with callgraph.

Any ideas. Is there a know issues with using xincludes here?

It might be quadratic behavior in the XInclude engine or something
else entirely. How large is glib-docs.xml after processing XIncludes?

See above. Btw. only the toplevel doc is using xincludes, the included
docs don't include other docs:

$grep "xi:inc" glib-docs.xml | wc -l



[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]