Performance Regression in v0.3.6 with LazyNode Usage

[s-fuerst]

I’ve encountered a severe performance regression in version v0.3.6 when using LazyNode.

Example code:

using XML
using CodecZlib

stream = GzipDecompressorStream(open("berlin-v5.5.3-1pct.output_plans.xml.gz"))

pos = read(stream, LazyNode)

function next_tag(pos, search)
    pos = next(pos)
    while tag(pos) != search
        pos = next(pos)
        if pos === nothing
            return nothing
        end
    end
    pos
end

next_tag(pos, "person")

@time next_tag(pos, "person")

The test file can be downloaded from:
https://svn.vsp.tu-berlin.de/repos/public-svn/matsim/scenarios/countries/de/berlin/berlin-v5.5-1pct/output-berlin-v5.5-1pct/berlin-v5.5.3-1pct.output_plans.xml.gz

Results:

• v0.3.5: next_tag executes in ~4 µs
• v0.3.6: The same call takes ~8 seconds — around 2 million times slower.

This issue occurs both with compressed (gzip) and uncompressed streams.

[TimG1964]

This is a result of PR #45, seeking to address issue #43. See my comment in issue #43. I hope to make a PR with a fix very soon but, in the mean time, I suggest to use v0,3,5 if this is a problem.

Assuming the file you've linked does not use the xml:space attribute at all, the performance in the forthcoming PR will be pretty much identical to that of 0.3.5. Here is a quick benchmark of your script, above (using the putative PR):

julia> @benchmark next_tag(pos, "person")
BenchmarkTools.Trial: 10000 samples with 118 evaluations per sample.
 Range (min … max):  744.915 ns … 352.232 μs  ┊ GC (min … max):  0.00% … 99.63%
 Time  (median):       1.529 μs               ┊ GC (median):     0.00%
 Time  (mean ± σ):     1.553 μs ±   5.205 μs  ┊ GC (mean ± σ):  13.19% ±  4.51%

  ▅█▇▃▁        ▂▆▆▄▁    ▃▇█▇▅▄▃▂▁  ▁                            ▂
  █████▇▅▆▅▇██▅██████▇▇█████████████████▇▆▆▆▆▆▆▆▆▅▅▇▆▆▄▆▅▂▅▅▆▇▇ █
  745 ns        Histogram: log(frequency) by time       2.94 μs <

 Memory estimate: 3.27 KiB, allocs estimate: 66.

(Edit: not sure why the bar chart above doesn't paste well...)

[ronisbr]

Murphy's Law is very true! I am writing a package to parse and create Orbit Data Messages for the SatelliteToolbox.jl ecosystem. Those files are XML files that can be very large sometimes. I started coding somedays ago and the XML version was 0.3.6. It took 7s to parse a file with 192 messages that EzXML was taking 0.05s. Hence, I, obviously, started using EzXML but very sad because I prefer 100%-pure Julia solutions.

Now, I saw this issue, updated the version, and XML.jl is parsing the same file in 0.02s now!

Thanks @joshday for this amazing package!

[joshday]

@ronisbr: thank @TimG1964! I merely clicked merge 😅

[ronisbr]

Thanks @TimG1964 !