From acd23a33d837d03c813212ec3896a86edef16e87 Mon Sep 17 00:00:00 2001 From: =?utf8?q?Kim=20Nguy=E1=BB=85n?= Date: Wed, 24 Apr 2013 18:42:24 +0200 Subject: [PATCH] Add a bitmap to keep track of whether a subtree needs to be recomputed or not. A subtree needs to be recomputed when: (1) it's todo transition list is not empty or (2) one of its subtrees needs to be recomputed. Introduce a bitvector module to efficiently represent arrays of booleans. --- Remakefile.in | 4 +- src/ata.ml | 8 +- src/ata.mli | 2 +- src/bitvector.ml | 36 +++ src/bitvector.mli | 9 + src/eval.ml | 116 ++++++---- tests/alphabet.xml.summary | 413 ++++++++++++++++++++-------------- tests/comments00.xml.summary | 8 +- tests/xmark_small.xml.summary | 327 ++++++++++++++++----------- tests/xmark_tiny.xml.summary | 327 ++++++++++++++++----------- 10 files changed, 765 insertions(+), 485 deletions(-) create mode 100644 src/bitvector.ml create mode 100644 src/bitvector.mli diff --git a/Remakefile.in b/Remakefile.in index f5ba98d..3f16f26 100644 --- a/Remakefile.in +++ b/Remakefile.in @@ -172,13 +172,13 @@ test_clean: echo "Query: $q : $query" >> "$1" cat "$LOG" | grep '^STATS' >> "$1" echo -n "Diff: " >> "$1" - tools/xml_diff.native "$REF" "$OUTPUT" >/dev/null 2>&1 - if [ "$?" -eq 0 ]; then + if tools/xml_diff.native "$REF" "$OUTPUT" >/dev/null 2>&1; then echo ok echo ok >> "$1" else echo failed echo failed >> "$1" + exit 1 fi echo '-------------------------------------------' >> "$1" done diff --git a/src/ata.ml b/src/ata.ml index 9fe128a..01fa639 100644 --- a/src/ata.ml +++ b/src/ata.ml @@ -14,7 +14,7 @@ (***********************************************************************) (* - Time-stamp: + Time-stamp: *) INCLUDE "utils.ml" @@ -199,6 +199,8 @@ type config = { unsat : StateSet.t; todo : TransList.t; summary : node_summary; + (** optimization infos, + not taken into account during hashconsing *) mutable round : int; } @@ -240,7 +242,7 @@ let dummy_config = Config.make { sat = StateSet.empty; unsat = StateSet.empty; todo = TransList.nil; summary = dummy_summary; - round = 0 + round = 0; } @@ -442,7 +444,7 @@ let eval_trans auto fcs nss ps ss = let unsat = StateSet.union unsat (StateSet.diff removed kept) in (* States that were found once to be satisfiable remain so *) let unsat = StateSet.diff unsat sat in - let new_config = Config.make { sat; unsat; todo ; summary = old_summary ; round = 0 } in + let new_config = Config.make { old_config.Config.node with sat; unsat; todo; } in Cache.N4.add auto.cache4 oid fcsid nssid psid new_config; new_config in diff --git a/src/ata.mli b/src/ata.mli index 0861773..8a1119e 100644 --- a/src/ata.mli +++ b/src/ata.mli @@ -14,7 +14,7 @@ (***********************************************************************) (* - Time-stamp: + Time-stamp: *) type predicate = diff --git a/src/bitvector.ml b/src/bitvector.ml new file mode 100644 index 0000000..a44a58e --- /dev/null +++ b/src/bitvector.ml @@ -0,0 +1,36 @@ +type t = { length : int; + bits : string; } + +let create ?(init=false) size = + let i = if init then '\xff' else '\x00' in + { length = size; + bits = String.make (1 + size / 8) i + } + +let length v = v.length + +let unsafe_get v n = + let i = n / 8 + and j = n mod 8 in + (((Char.code (String.unsafe_get v.bits i)) lsr j) land 1) == 1 + + +let unsafe_set v n (b:bool) = + let x : int = Obj.magic b in + let i = n / 8 + and j = n mod 8 in + let m = 1 lsl j in + let w = Char.code (String.unsafe_get v.bits i) in + let w = (w land lnot m) lor (~-x land m) in + String.unsafe_set v.bits i (Char.unsafe_chr (w land 0xff)) +;; + +let get v n = + if n < 0 || n >= v.length then failwith "Bitvector.get" + else unsafe_get v n +;; + +let set v n b = + if n < 0 || n >= v.length then failwith "Bitvector.set" + else unsafe_set v n b +;; diff --git a/src/bitvector.mli b/src/bitvector.mli new file mode 100644 index 0000000..2bd31eb --- /dev/null +++ b/src/bitvector.mli @@ -0,0 +1,9 @@ +type t + +val create : ?init:bool -> int -> t +val length : t -> int +val set : t -> int -> bool -> unit +val get : t -> int -> bool + +val unsafe_set : t -> int -> bool -> unit +val unsafe_get : t -> int -> bool diff --git a/src/eval.ml b/src/eval.ml index 22a3b5f..d90be92 100644 --- a/src/eval.ml +++ b/src/eval.ml @@ -14,7 +14,7 @@ (***********************************************************************) (* - Time-stamp: + Time-stamp: *) INCLUDE "utils.ml" @@ -38,14 +38,14 @@ END let config = config.Ata.Config.node in let oldi = config.Ata.round in Html.trace (T.preorder tree node) i oldi - "%s
sat: %a
unsat: %a
todo: %around: %i
" + "node: %i
%s
sat: %a
unsat: %a
todo: %around: %i
" + ((T.preorder tree node):>int) msg StateSet.print config.Ata.sat StateSet.print config.Ata.unsat (Ata.TransList.print ~sep:"
") config.Ata.todo oldi - type cache = StateSet.t Cache.N1.t let get c t n = Cache.N1.find c (T.preorder t n) let set c t n v i = @@ -53,10 +53,19 @@ END Cache.N1.add c (T.preorder t n) v - let top_down_run auto tree node cache _i = - let redo = ref false in + type run = { config : Ata.Config.t Cache.N1.t; + unstable : Bitvector.t; + mutable redo : bool; + mutable pass : int; + } + + + let top_down_run auto tree node run = + let cache = run.config in + let unstable = run.unstable in + let _i = run.pass in let rec loop node = - if node != T.nil then begin + if node == T.nil then false else begin let parent = T.parent tree node in let fc = T.first_child tree node in let ns = T.next_sibling tree node in @@ -64,16 +73,16 @@ END let config0 = let c = get cache tree node in if c == Cache.N1.dummy cache then - Ata.Config.make - { c.Ata.Config.node with - Ata.todo = Ata.get_trans auto tag auto.Ata.states; - summary = Ata.node_summary - (node == T.first_child tree parent) (* is_left *) - (node == T.next_sibling tree parent) (* is_right *) - (fc != T.nil) (* has_left *) - (ns != T.nil) (* has_right *) - (T.kind tree node) (* kind *) - } + Ata.Config.make + { c.Ata.Config.node with + Ata.todo = Ata.get_trans auto tag auto.Ata.states; + summary = Ata.node_summary + (node == T.first_child tree parent) (* is_left *) + (node == T.next_sibling tree parent) (* is_right *) + (fc != T.nil) (* has_left *) + (ns != T.nil) (* has_right *) + (T.kind tree node) (* kind *) + } else c in @@ -87,29 +96,32 @@ END TRACE(html tree node _i config1 "Updating transitions"); if config0 != config1 then set cache tree node config1 _i; - let () = loop fc in + let old_unstable_left = Bitvector.unsafe_get unstable (T.preorder tree fc) in + let unstable_left = old_unstable_left && loop fc in let fcs1 = get cache tree fc in let config2 = Ata.eval_trans auto fcs1 nss ps config1 in TRACE(html tree node _i config2 "Updating transitions (after first-child)"); if config1 != config2 then set cache tree node config2 _i; - let () = loop ns in - let config3 = Ata.eval_trans auto fcs1 (get cache tree ns) ps config2 in + let old_unstable_right = Bitvector.unsafe_get unstable (T.preorder tree ns) in + let unstable_right = old_unstable_right && loop ns in + let nss1 = get cache tree ns in + let config3 = Ata.eval_trans auto fcs1 nss1 ps config2 in TRACE(html tree node _i config3 "Updating transitions (after next-sibling)"); if config2 != config3 then set cache tree node config3 _i; - (* We do set the redo flat if : *) - if not ( - config0 == config3 (* did not gain any new information *) - || !redo (* already set *) - || Ata.TransList.nil == config3.Ata.Config.node.Ata.todo ) (* no more transition to check *) - then redo := true + let unstable_self = + unstable_left + || unstable_right + || Ata.(TransList.nil != config3.Config.node.todo) + in + Bitvector.unsafe_set unstable (T.preorder tree node) unstable_self; + unstable_self end in - loop node; - !redo + loop node let get_results auto tree node cache = let rec loop node acc = @@ -125,27 +137,45 @@ END in loop node [] + + let stats run = + let count = ref 0 in + let len = Bitvector.length run.unstable in + for i = 0 to len - 1 do + if not (Bitvector.unsafe_get run.unstable i) then + incr count + done; + eprintf "@[STATS: %i nodes over %i were skipped in iteration %i (%.2f %%), redo is: %b@]@." + !count len run.pass (100. *. (float !count /. float len)) + run.redo + + let eval auto tree node = - let cache = Cache.N1.create - (Ata.Config.make { Ata.sat = StateSet.empty; - Ata.unsat = StateSet.empty; - Ata.todo = Ata.TransList.nil; - Ata.summary = Ata.dummy_summary; - Ata.round = ~-1; - }) + let run = { config = Cache.N1.create + Ata.(Config.make { sat = StateSet.empty; + unsat = StateSet.empty; + todo = TransList.nil; + summary = dummy_summary; + round = ~-1 + }); + unstable = Bitvector.create ~init:true (T.size tree); + redo = true; + pass = 0 + } in - let redo = ref true in - let iter = ref 0 in - Ata.reset auto; - while !redo do - redo := false; + while run.redo do + run.redo <- false; Ata.reset auto; (* prevents the .cache2 and .cache4 memoization tables from growing too much *) - redo := top_down_run auto tree node cache !iter; - incr iter; + run.redo <- top_down_run auto tree node run; + stats run; + run.pass <- run.pass + 1; done; - at_exit (fun () -> eprintf "@[STATS: %i iterations@]@." !iter); - let r = get_results auto tree node cache in + at_exit (fun () -> eprintf "@[STATS: %i iterations@]@." run.pass); + at_exit (fun () -> stats run); + let r = get_results auto tree node run.config in + TRACE(Html.gen_trace (module T : Tree.S with type t = T.t) (tree)); + r end diff --git a/tests/alphabet.xml.summary b/tests/alphabet.xml.summary index 07b834b..f579698 100644 --- a/tests/alphabet.xml.summary +++ b/tests/alphabet.xml.summary @@ -1,11 +1,13 @@ Query: A1 : //L/* -STATS: parsing xml document: 0.240088ms -STATS: parsing XPath query: 0.041008ms -STATS: compiling XPath query: 0.134945ms +STATS: parsing xml document: 0.378132ms +STATS: parsing XPath query: 0.042200ms +STATS: compiling XPath query: 0.200033ms STATS: Query: /descendant-or-self::node()/child::L/child::* STATS: Automaton: -STATS: evaluating query: 2.089024ms -STATS: serializing results: 1.500845ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.099991ms +STATS: serializing results: 1.550913ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -13,13 +15,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: A2 : //L/parent::* -STATS: parsing xml document: 0.361919ms -STATS: parsing XPath query: 0.053167ms -STATS: compiling XPath query: 0.160933ms +STATS: parsing xml document: 0.357151ms +STATS: parsing XPath query: 0.052929ms +STATS: compiling XPath query: 0.162125ms STATS: Query: /descendant-or-self::node()/child::L/parent::* STATS: Automaton: -STATS: evaluating query: 2.071142ms -STATS: serializing results: 1.811028ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.071857ms +STATS: serializing results: 1.896143ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1310 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -27,13 +31,15 @@ STATS: cache4: length: 1464, used: 154, occupation: 0.105191 Diff: ok ------------------------------------------- Query: A3 : //L/descendant::* -STATS: parsing xml document: 0.359774ms -STATS: parsing XPath query: 0.046015ms +STATS: parsing xml document: 0.369072ms +STATS: parsing XPath query: 0.044823ms STATS: compiling XPath query: 0.216961ms STATS: Query: /descendant-or-self::node()/child::L/descendant::* STATS: Automaton: -STATS: evaluating query: 2.213001ms -STATS: serializing results: 1.619101ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.236843ms +STATS: serializing results: 1.821041ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 918 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -41,13 +47,15 @@ STATS: cache4: length: 1060, used: 142, occupation: 0.133962 Diff: ok ------------------------------------------- Query: A4 : //L/descendant-or-self::* -STATS: parsing xml document: 0.376225ms -STATS: parsing XPath query: 0.043869ms -STATS: compiling XPath query: 0.181913ms +STATS: parsing xml document: 0.360012ms +STATS: parsing XPath query: 0.048876ms +STATS: compiling XPath query: 0.190020ms STATS: Query: /descendant-or-self::node()/child::L/descendant-or-self::* STATS: Automaton: -STATS: evaluating query: 2.362013ms -STATS: serializing results: 1.754999ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.301931ms +STATS: serializing results: 1.735926ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 918 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -55,13 +63,15 @@ STATS: cache4: length: 1060, used: 142, occupation: 0.133962 Diff: ok ------------------------------------------- Query: A5 : //L/ancestor::* -STATS: parsing xml document: 0.407934ms -STATS: parsing XPath query: 0.046015ms +STATS: parsing xml document: 0.365973ms +STATS: parsing XPath query: 0.046968ms STATS: compiling XPath query: 0.174046ms STATS: Query: /descendant-or-self::node()/child::L/ancestor::* STATS: Automaton: -STATS: evaluating query: 2.144098ms -STATS: serializing results: 2.022982ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.151966ms +STATS: serializing results: 2.042055ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1320 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -69,13 +79,15 @@ STATS: cache4: length: 1476, used: 156, occupation: 0.105691 Diff: ok ------------------------------------------- Query: A6 : //L/ancestor-or-self::* -STATS: parsing xml document: 0.368118ms -STATS: parsing XPath query: 0.048161ms -STATS: compiling XPath query: 0.205040ms +STATS: parsing xml document: 0.365973ms +STATS: parsing XPath query: 0.045061ms +STATS: compiling XPath query: 0.201941ms STATS: Query: /descendant-or-self::node()/child::L/ancestor-or-self::* STATS: Automaton: -STATS: evaluating query: 2.430916ms -STATS: serializing results: 2.072096ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.483130ms +STATS: serializing results: 2.204895ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1242 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -83,13 +95,15 @@ STATS: cache4: length: 1397, used: 155, occupation: 0.110952 Diff: ok ------------------------------------------- Query: A7 : //L/following-sibling::* -STATS: parsing xml document: 0.356913ms -STATS: parsing XPath query: 0.049829ms -STATS: compiling XPath query: 0.161886ms +STATS: parsing xml document: 0.365019ms +STATS: parsing XPath query: 0.051975ms +STATS: compiling XPath query: 0.164032ms STATS: Query: /descendant-or-self::node()/child::L/following-sibling::* STATS: Automaton: -STATS: evaluating query: 1.810074ms -STATS: serializing results: 1.445055ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.899004ms +STATS: serializing results: 1.600981ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1051 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -97,13 +111,15 @@ STATS: cache4: length: 1173, used: 122, occupation: 0.104007 Diff: ok ------------------------------------------- Query: A8 : //L/preceding-sibling::* -STATS: parsing xml document: 0.368118ms -STATS: parsing XPath query: 0.057936ms -STATS: compiling XPath query: 0.161171ms +STATS: parsing xml document: 0.366926ms +STATS: parsing XPath query: 0.055075ms +STATS: compiling XPath query: 0.163078ms STATS: Query: /descendant-or-self::node()/child::L/preceding-sibling::* STATS: Automaton: -STATS: evaluating query: 1.960993ms -STATS: serializing results: 1.580954ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.027035ms +STATS: serializing results: 1.585960ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1174 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -111,13 +127,15 @@ STATS: cache4: length: 1314, used: 140, occupation: 0.106545 Diff: ok ------------------------------------------- Query: A9 : //L/following::* -STATS: parsing xml document: 0.391960ms -STATS: parsing XPath query: 0.050068ms -STATS: compiling XPath query: 0.283003ms +STATS: parsing xml document: 0.361919ms +STATS: parsing XPath query: 0.051022ms +STATS: compiling XPath query: 0.282049ms STATS: Query: /descendant-or-self::node()/child::L/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::* STATS: Automaton: -STATS: evaluating query: 6.573200ms -STATS: serializing results: 1.810789ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 6.561041ms +STATS: serializing results: 1.834869ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 2104 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -125,13 +143,16 @@ STATS: cache4: length: 2334, used: 230, occupation: 0.098543 Diff: ok ------------------------------------------- Query: A10 : //L/preceding::* -STATS: parsing xml document: 0.389814ms -STATS: parsing XPath query: 0.053883ms -STATS: compiling XPath query: 0.276089ms +STATS: parsing xml document: 0.365973ms +STATS: parsing XPath query: 0.056982ms +STATS: compiling XPath query: 0.277996ms STATS: Query: /descendant-or-self::node()/child::L/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::* STATS: Automaton: -STATS: evaluating query: 8.272886ms -STATS: serializing results: 1.735926ms +STATS: 7 nodes over 129 were skipped in iteration 0 (5.43 %), redo is: true +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 8.136034ms +STATS: serializing results: 2.127886ms +STATS: 129 nodes over 129 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations STATS: automaton 0, cache2: 0 entries, cache6: 942 entries STATS: cache2: length: 0, used: 0, occupation: -nan @@ -139,13 +160,15 @@ STATS: cache4: length: 1077, used: 135, occupation: 0.125348 Diff: ok ------------------------------------------- Query: A11 : //L/self::* -STATS: parsing xml document: 0.360966ms -STATS: parsing XPath query: 0.071049ms -STATS: compiling XPath query: 0.149012ms +STATS: parsing xml document: 0.369787ms +STATS: parsing XPath query: 0.046968ms +STATS: compiling XPath query: 0.160933ms STATS: Query: /descendant-or-self::node()/child::L/self::* STATS: Automaton: -STATS: evaluating query: 1.744986ms -STATS: serializing results: 1.600027ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.785040ms +STATS: serializing results: 1.600981ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 837 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -153,13 +176,15 @@ STATS: cache4: length: 946, used: 109, occupation: 0.115222 Diff: ok ------------------------------------------- Query: A12 : //L/@id/parent::* -STATS: parsing xml document: 0.376225ms -STATS: parsing XPath query: 0.060081ms -STATS: compiling XPath query: 0.236034ms +STATS: parsing xml document: 0.363111ms +STATS: parsing XPath query: 0.061035ms +STATS: compiling XPath query: 0.235796ms STATS: Query: /descendant-or-self::node()/child::L/attribute::@id/parent::* STATS: Automaton: -STATS: evaluating query: 3.020048ms -STATS: serializing results: 1.641035ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 3.045082ms +STATS: serializing results: 1.613855ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1594 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -167,13 +192,15 @@ STATS: cache4: length: 1750, used: 156, occupation: 0.089143 Diff: ok ------------------------------------------- Query: P1 : //*[L] -STATS: parsing xml document: 0.376940ms -STATS: parsing XPath query: 0.045061ms -STATS: compiling XPath query: 0.167131ms +STATS: parsing xml document: 0.360966ms +STATS: parsing XPath query: 0.049114ms +STATS: compiling XPath query: 0.162125ms STATS: Query: /descendant-or-self::node()/child::*[ child::L ] STATS: Automaton: -STATS: evaluating query: 1.850128ms -STATS: serializing results: 1.837015ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.814127ms +STATS: serializing results: 1.966953ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1326 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -181,13 +208,15 @@ STATS: cache4: length: 1480, used: 154, occupation: 0.104054 Diff: ok ------------------------------------------- Query: P2 : //*[parent::L] -STATS: parsing xml document: 0.367165ms +STATS: parsing xml document: 0.390053ms STATS: parsing XPath query: 0.052929ms -STATS: compiling XPath query: 0.167847ms +STATS: compiling XPath query: 0.167131ms STATS: Query: /descendant-or-self::node()/child::*[ parent::L ] STATS: Automaton: -STATS: evaluating query: 1.810074ms -STATS: serializing results: 1.551867ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.857996ms +STATS: serializing results: 2.467155ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -195,13 +224,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: P3 : //*[descendant::L] -STATS: parsing xml document: 0.373125ms -STATS: parsing XPath query: 0.058889ms -STATS: compiling XPath query: 0.169039ms +STATS: parsing xml document: 0.428915ms +STATS: parsing XPath query: 0.049114ms +STATS: compiling XPath query: 0.166178ms STATS: Query: /descendant-or-self::node()/child::*[ descendant::L ] STATS: Automaton: -STATS: evaluating query: 0.701904ms -STATS: serializing results: 2.130032ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.492189ms +STATS: serializing results: 2.094984ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1336 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -209,13 +240,15 @@ STATS: cache4: length: 1492, used: 156, occupation: 0.104558 Diff: ok ------------------------------------------- Query: P4 : //*[descendant-or-self::L] -STATS: parsing xml document: 0.359058ms -STATS: parsing XPath query: 0.046968ms -STATS: compiling XPath query: 0.170946ms +STATS: parsing xml document: 0.363111ms +STATS: parsing XPath query: 0.050068ms +STATS: compiling XPath query: 0.177860ms STATS: Query: /descendant-or-self::node()/child::*[ descendant-or-self::L ] STATS: Automaton: -STATS: evaluating query: 2.156973ms -STATS: serializing results: 2.150059ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.146959ms +STATS: serializing results: 2.099037ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1242 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -223,13 +256,15 @@ STATS: cache4: length: 1397, used: 155, occupation: 0.110952 Diff: ok ------------------------------------------- Query: P5 : //*[ancestor::L] -STATS: parsing xml document: 0.401020ms -STATS: parsing XPath query: 0.049829ms -STATS: compiling XPath query: 0.191927ms +STATS: parsing xml document: 0.357151ms +STATS: parsing XPath query: 0.049114ms +STATS: compiling XPath query: 0.241995ms STATS: Query: /descendant-or-self::node()/child::*[ ancestor::L ] STATS: Automaton: -STATS: evaluating query: 1.928091ms -STATS: serializing results: 1.629114ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.984835ms +STATS: serializing results: 1.695156ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 918 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -237,13 +272,15 @@ STATS: cache4: length: 1060, used: 142, occupation: 0.133962 Diff: ok ------------------------------------------- Query: P6 : //*[ancestor-or-self::L] -STATS: parsing xml document: 0.414848ms -STATS: parsing XPath query: 0.048876ms -STATS: compiling XPath query: 0.191927ms +STATS: parsing xml document: 0.168085ms +STATS: parsing XPath query: 0.026941ms +STATS: compiling XPath query: 0.084162ms STATS: Query: /descendant-or-self::node()/child::*[ ancestor-or-self::L ] STATS: Automaton: -STATS: evaluating query: 1.888990ms -STATS: serializing results: 1.803875ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.060963ms +STATS: serializing results: 1.700878ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 918 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -251,13 +288,15 @@ STATS: cache4: length: 1060, used: 142, occupation: 0.133962 Diff: ok ------------------------------------------- Query: P7 : //*[following-sibling::L] -STATS: parsing xml document: 0.370026ms +STATS: parsing xml document: 0.364065ms STATS: parsing XPath query: 0.046968ms -STATS: compiling XPath query: 0.154972ms +STATS: compiling XPath query: 0.156879ms STATS: Query: /descendant-or-self::node()/child::*[ following-sibling::L ] STATS: Automaton: -STATS: evaluating query: 1.673937ms -STATS: serializing results: 1.567125ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.662016ms +STATS: serializing results: 1.580000ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1174 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -265,13 +304,15 @@ STATS: cache4: length: 1314, used: 140, occupation: 0.106545 Diff: ok ------------------------------------------- Query: P8 : //*[preceding-sibling::L] -STATS: parsing xml document: 0.365973ms -STATS: parsing XPath query: 0.051975ms -STATS: compiling XPath query: 0.156164ms +STATS: parsing xml document: 0.401974ms +STATS: parsing XPath query: 0.056982ms +STATS: compiling XPath query: 0.160933ms STATS: Query: /descendant-or-self::node()/child::*[ preceding-sibling::L ] STATS: Automaton: -STATS: evaluating query: 1.492977ms -STATS: serializing results: 1.503944ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.548767ms +STATS: serializing results: 1.600027ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1051 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -279,13 +320,16 @@ STATS: cache4: length: 1173, used: 122, occupation: 0.104007 Diff: ok ------------------------------------------- Query: P9 : //*[following::L] -STATS: parsing xml document: 0.374079ms -STATS: parsing XPath query: 0.050068ms -STATS: compiling XPath query: 0.241995ms +STATS: parsing xml document: 0.368118ms +STATS: parsing XPath query: 0.047922ms +STATS: compiling XPath query: 0.231981ms STATS: Query: /descendant-or-self::node()/child::*[ ancestor-or-self::node()/following-sibling::node()/descendant-or-self::L ] STATS: Automaton: -STATS: evaluating query: 6.485939ms -STATS: serializing results: 2.099037ms +STATS: 7 nodes over 129 were skipped in iteration 0 (5.43 %), redo is: true +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 6.533861ms +STATS: serializing results: 1.817942ms +STATS: 129 nodes over 129 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations STATS: automaton 0, cache2: 0 entries, cache6: 780 entries STATS: cache2: length: 0, used: 0, occupation: -nan @@ -293,13 +337,15 @@ STATS: cache4: length: 915, used: 135, occupation: 0.147541 Diff: ok ------------------------------------------- Query: P10 : //*[preceding::L] -STATS: parsing xml document: 0.376940ms -STATS: parsing XPath query: 0.058174ms -STATS: compiling XPath query: 0.231028ms +STATS: parsing xml document: 0.369072ms +STATS: parsing XPath query: 0.057936ms +STATS: compiling XPath query: 0.245810ms STATS: Query: /descendant-or-self::node()/child::*[ ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::L ] STATS: Automaton: -STATS: evaluating query: 3.906965ms -STATS: serializing results: 1.818180ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 3.724098ms +STATS: serializing results: 1.777172ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1767 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -307,13 +353,15 @@ STATS: cache4: length: 1980, used: 213, occupation: 0.107576 Diff: ok ------------------------------------------- Query: P11 : //*[self::L] -STATS: parsing xml document: 0.378132ms -STATS: parsing XPath query: 0.046015ms +STATS: parsing xml document: 0.367880ms +STATS: parsing XPath query: 0.048161ms STATS: compiling XPath query: 0.149965ms STATS: Query: /descendant-or-self::node()/child::*[ self::L ] STATS: Automaton: -STATS: evaluating query: 1.402855ms -STATS: serializing results: 1.636982ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.435041ms +STATS: serializing results: 1.670837ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 837 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -321,13 +369,15 @@ STATS: cache4: length: 946, used: 109, occupation: 0.115222 Diff: ok ------------------------------------------- Query: P12 : //*[@id] -STATS: parsing xml document: 0.376225ms -STATS: parsing XPath query: 0.043869ms -STATS: compiling XPath query: 0.188828ms +STATS: parsing xml document: 0.365019ms +STATS: parsing XPath query: 0.042915ms +STATS: compiling XPath query: 0.182867ms STATS: Query: /descendant-or-self::node()/child::*[ attribute::@id ] STATS: Automaton: -STATS: evaluating query: 1.538992ms -STATS: serializing results: 2.470970ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 1.521111ms +STATS: serializing results: 2.558947ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 907 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -335,13 +385,15 @@ STATS: cache4: length: 1022, used: 115, occupation: 0.112524 Diff: ok ------------------------------------------- Query: T1 : //L/text() -STATS: parsing xml document: 0.376940ms -STATS: parsing XPath query: 0.061035ms -STATS: compiling XPath query: 0.207186ms +STATS: parsing xml document: 0.377893ms +STATS: parsing XPath query: 0.059128ms +STATS: compiling XPath query: 0.205994ms STATS: Query: /descendant-or-self::node()/child::L/child::text() STATS: Automaton: -STATS: evaluating query: 2.085209ms -STATS: serializing results: 1.515150ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.229929ms +STATS: serializing results: 1.520872ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -349,13 +401,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: T2 : //L/comment() -STATS: parsing xml document: 0.368118ms -STATS: parsing XPath query: 0.070095ms -STATS: compiling XPath query: 0.197172ms +STATS: parsing xml document: 0.365973ms +STATS: parsing XPath query: 0.068903ms +STATS: compiling XPath query: 0.198841ms STATS: Query: /descendant-or-self::node()/child::L/child::comment() STATS: Automaton: -STATS: evaluating query: 2.050161ms -STATS: serializing results: 1.537085ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.146959ms +STATS: serializing results: 1.429081ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -363,13 +417,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: T3 : //L/processing-instruction() -STATS: parsing xml document: 0.409842ms -STATS: parsing XPath query: 0.066042ms -STATS: compiling XPath query: 0.194788ms +STATS: parsing xml document: 0.365019ms +STATS: parsing XPath query: 0.082016ms +STATS: compiling XPath query: 0.207186ms STATS: Query: /descendant-or-self::node()/child::L/child::processing-instruction() STATS: Automaton: -STATS: evaluating query: 2.111912ms -STATS: serializing results: 1.474142ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.242804ms +STATS: serializing results: 1.472950ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -377,13 +433,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: T4 : //L/processing-instruction("myPI") -STATS: parsing xml document: 0.370979ms +STATS: parsing xml document: 0.367880ms STATS: parsing XPath query: 0.077009ms -STATS: compiling XPath query: 0.200033ms +STATS: compiling XPath query: 0.201941ms STATS: Query: /descendant-or-self::node()/child::L/child::processing-instruction('?myPI') STATS: Automaton: -STATS: evaluating query: 2.094984ms -STATS: serializing results: 1.549959ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.152920ms +STATS: serializing results: 1.482964ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -391,13 +449,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: T5 : //L/node() -STATS: parsing xml document: 0.376940ms -STATS: parsing XPath query: 0.066042ms -STATS: compiling XPath query: 0.196934ms +STATS: parsing xml document: 0.361919ms +STATS: parsing XPath query: 0.064850ms +STATS: compiling XPath query: 0.202179ms STATS: Query: /descendant-or-self::node()/child::L/child::node() STATS: Automaton: -STATS: evaluating query: 2.347946ms -STATS: serializing results: 1.650810ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.159119ms +STATS: serializing results: 1.833200ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -405,13 +465,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: T6 : //L/N -STATS: parsing xml document: 0.380993ms -STATS: parsing XPath query: 0.046968ms -STATS: compiling XPath query: 0.207901ms +STATS: parsing xml document: 0.365973ms +STATS: parsing XPath query: 0.048161ms +STATS: compiling XPath query: 0.202894ms STATS: Query: /descendant-or-self::node()/child::L/child::N STATS: Automaton: -STATS: evaluating query: 2.187967ms -STATS: serializing results: 1.534939ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.237082ms +STATS: serializing results: 1.518011ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 819 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -419,13 +481,15 @@ STATS: cache4: length: 952, used: 133, occupation: 0.139706 Diff: ok ------------------------------------------- Query: T7 : //L/* -STATS: parsing xml document: 0.377178ms -STATS: parsing XPath query: 0.045061ms -STATS: compiling XPath query: 0.200033ms +STATS: parsing xml document: 0.368834ms +STATS: parsing XPath query: 0.044107ms +STATS: compiling XPath query: 0.208139ms STATS: Query: /descendant-or-self::node()/child::L/child::* STATS: Automaton: -STATS: evaluating query: 2.017975ms -STATS: serializing results: 4.548073ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 2.174854ms +STATS: serializing results: 1.671076ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 809 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -433,13 +497,15 @@ STATS: cache4: length: 933, used: 124, occupation: 0.132905 Diff: ok ------------------------------------------- Query: O1 : //*[child::* and preceding::Q] -STATS: parsing xml document: 0.369072ms -STATS: parsing XPath query: 0.070095ms -STATS: compiling XPath query: 0.281096ms +STATS: parsing xml document: 0.364065ms +STATS: parsing XPath query: 0.056982ms +STATS: compiling XPath query: 0.263929ms STATS: Query: /descendant-or-self::node()/child::*[ child::* and ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::Q ] STATS: Automaton: -STATS: evaluating query: 5.612135ms -STATS: serializing results: 1.718998ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 5.656004ms +STATS: serializing results: 1.590014ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1873 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -447,13 +513,15 @@ STATS: cache4: length: 2090, used: 217, occupation: 0.103828 Diff: ok ------------------------------------------- Query: O2 : //*[not(child::*) and preceding::Q] -STATS: parsing xml document: 0.373125ms -STATS: parsing XPath query: 0.063896ms -STATS: compiling XPath query: 0.267982ms +STATS: parsing xml document: 0.366926ms +STATS: parsing XPath query: 0.066996ms +STATS: compiling XPath query: 0.342131ms STATS: Query: /descendant-or-self::node()/child::*[ not(child::*) and ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::Q ] STATS: Automaton: -STATS: evaluating query: 5.904198ms -STATS: serializing results: 1.775026ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 5.630016ms +STATS: serializing results: 1.742125ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 1873 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 @@ -461,27 +529,32 @@ STATS: cache4: length: 2090, used: 217, occupation: 0.103828 Diff: ok ------------------------------------------- Query: O3 : //*[preceding::L or following::L] -STATS: parsing xml document: 0.377893ms -STATS: parsing XPath query: 0.057936ms -STATS: compiling XPath query: 0.330925ms +STATS: parsing xml document: 0.363111ms +STATS: parsing XPath query: 0.063896ms +STATS: compiling XPath query: 0.329971ms STATS: Query: /descendant-or-self::node()/child::*[ ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::L or ancestor-or-self::node()/following-sibling::node()/descendant-or-self::L ] STATS: Automaton: -STATS: evaluating query: 10.947943ms -STATS: serializing results: 2.008915ms +STATS: 7 nodes over 129 were skipped in iteration 0 (5.43 %), redo is: true +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 10.987997ms +STATS: serializing results: 2.089977ms +STATS: 129 nodes over 129 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations STATS: automaton 0, cache2: 0 entries, cache6: 610 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 778, used: 168, occupation: 0.215938 +STATS: cache4: length: 777, used: 167, occupation: 0.214929 Diff: ok ------------------------------------------- Query: O4 : //L/ancestor::* | //L/descendant::* -STATS: parsing xml document: 0.390053ms -STATS: parsing XPath query: 0.050068ms -STATS: compiling XPath query: 0.411987ms +STATS: parsing xml document: 0.373125ms +STATS: parsing XPath query: 0.052214ms +STATS: compiling XPath query: 0.380039ms STATS: Query: /descendant-or-self::node()/child::L/ancestor::* | /descendant-or-self::node()/child::L/descendant::* STATS: Automaton: -STATS: evaluating query: 7.326841ms -STATS: serializing results: 2.140045ms +STATS: 129 nodes over 129 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 7.322073ms +STATS: serializing results: 2.199173ms +STATS: 129 nodes over 129 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 70 entries, cache6: 2345 entries STATS: cache2: length: 105, used: 35, occupation: 0.333333 diff --git a/tests/comments00.xml.summary b/tests/comments00.xml.summary index 7d9b4fb..b595152 100644 --- a/tests/comments00.xml.summary +++ b/tests/comments00.xml.summary @@ -1,11 +1,13 @@ Query: C0 : /descendant::comment() -STATS: parsing xml document: 0.124931ms +STATS: parsing xml document: 0.118017ms STATS: parsing XPath query: 0.057936ms STATS: compiling XPath query: 0.087023ms STATS: Query: /descendant::comment() STATS: Automaton: -STATS: evaluating query: 0.080109ms -STATS: serializing results: 1.444817ms +STATS: 3 nodes over 3 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 0.128031ms +STATS: serializing results: 1.478910ms +STATS: 3 nodes over 3 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 6 entries, cache6: 18 entries STATS: cache2: length: 9, used: 3, occupation: 0.333333 diff --git a/tests/xmark_small.xml.summary b/tests/xmark_small.xml.summary index 972a624..955e7ce 100644 --- a/tests/xmark_small.xml.summary +++ b/tests/xmark_small.xml.summary @@ -1,11 +1,13 @@ Query: A1 : /site/closed_auctions/closed_auction/annotation/description/text/keyword -STATS: parsing xml document: 195.340157ms -STATS: parsing XPath query: 0.084162ms -STATS: compiling XPath query: 0.221014ms +STATS: parsing xml document: 634.769201ms +STATS: parsing XPath query: 0.095844ms +STATS: compiling XPath query: 0.281096ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction/child::annotation/child::description/child::text/child::keyword STATS: Automaton: -STATS: evaluating query: 122.359991ms -STATS: serializing results: 3.302097ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 119.843006ms +STATS: serializing results: 3.608942ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 3149 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -13,13 +15,15 @@ STATS: cache4: length: 3464, used: 315, occupation: 0.090935 Diff: ok ------------------------------------------- Query: A2 : //closed_auction//keyword -STATS: parsing xml document: 190.065861ms -STATS: parsing XPath query: 0.062227ms -STATS: compiling XPath query: 0.133991ms +STATS: parsing xml document: 191.257000ms +STATS: parsing XPath query: 0.056028ms +STATS: compiling XPath query: 0.144005ms STATS: Query: /descendant-or-self::node()/child::closed_auction/descendant-or-self::node()/child::keyword STATS: Automaton: -STATS: evaluating query: 136.409998ms -STATS: serializing results: 6.726027ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 130.471945ms +STATS: serializing results: 6.496906ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 2681 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -27,13 +31,15 @@ STATS: cache4: length: 2915, used: 234, occupation: 0.080274 Diff: ok ------------------------------------------- Query: A3 : /site/closed_auctions/closed_auction//keyword -STATS: parsing xml document: 194.837809ms -STATS: parsing XPath query: 0.064850ms -STATS: compiling XPath query: 0.159979ms +STATS: parsing xml document: 189.831018ms +STATS: parsing XPath query: 0.063896ms +STATS: compiling XPath query: 0.157118ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction/descendant-or-self::node()/child::keyword STATS: Automaton: -STATS: evaluating query: 126.852036ms -STATS: serializing results: 6.720066ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 139.882088ms +STATS: serializing results: 6.744862ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 3277 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -41,83 +47,100 @@ STATS: cache4: length: 3555, used: 278, occupation: 0.078200 Diff: ok ------------------------------------------- Query: A4 : /site/closed_auctions/closed_auction[annotation/description/text/keyword]/date -STATS: parsing xml document: 194.200039ms -STATS: parsing XPath query: 0.106812ms -STATS: compiling XPath query: 0.149012ms +STATS: parsing xml document: 189.064026ms +STATS: parsing XPath query: 0.106096ms +STATS: compiling XPath query: 0.199080ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction[ child::annotation/child::description/child::text/child::keyword ]/child::date STATS: Automaton: -STATS: evaluating query: 181.638002ms -STATS: serializing results: 2.104998ms +STATS: 245034 nodes over 254301 were skipped in iteration 0 (96.36 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 135.497093ms +STATS: serializing results: 2.182007ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1324 entries +STATS: automaton 0, cache2: 0 entries, cache6: 282 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1501, used: 177, occupation: 0.117921 +STATS: cache4: length: 355, used: 73, occupation: 0.205634 Diff: ok ------------------------------------------- Query: A5 : /site/closed_auctions/closed_auction[descendant::keyword]/date -STATS: parsing xml document: 190.989017ms -STATS: parsing XPath query: 0.068903ms -STATS: compiling XPath query: 0.144958ms +STATS: parsing xml document: 190.711021ms +STATS: parsing XPath query: 0.084162ms +STATS: compiling XPath query: 0.134945ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction[ descendant::keyword ]/child::date STATS: Automaton: -STATS: evaluating query: 182.102919ms -STATS: serializing results: 2.466917ms +STATS: 245034 nodes over 254301 were skipped in iteration 0 (96.36 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 138.205051ms +STATS: serializing results: 2.486944ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1170 entries +STATS: automaton 0, cache2: 0 entries, cache6: 259 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1328, used: 158, occupation: 0.118976 +STATS: cache4: length: 342, used: 83, occupation: 0.242690 Diff: ok ------------------------------------------- Query: A6 : /site/people/person[profile/gender and profile/age]/name -STATS: parsing xml document: 187.790871ms -STATS: parsing XPath query: 0.055075ms -STATS: compiling XPath query: 0.154972ms +STATS: parsing xml document: 185.791016ms +STATS: parsing XPath query: 0.102043ms +STATS: compiling XPath query: 0.155210ms STATS: Query: /child::site/child::people/child::person[ child::profile/child::gender and child::profile/child::age ]/child::name STATS: Automaton: -STATS: evaluating query: 172.993898ms -STATS: serializing results: 2.465010ms +STATS: 236309 nodes over 254301 were skipped in iteration 0 (92.92 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 149.569035ms +STATS: serializing results: 2.363920ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 2174 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1570 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 2385, used: 211, occupation: 0.088470 +STATS: cache4: length: 1719, used: 149, occupation: 0.086678 Diff: ok ------------------------------------------- Query: A7 : /site/people/person[phone or homepage]/name -STATS: parsing xml document: 193.610907ms -STATS: parsing XPath query: 0.076056ms -STATS: compiling XPath query: 0.150919ms +STATS: parsing xml document: 187.725067ms +STATS: parsing XPath query: 0.087023ms +STATS: compiling XPath query: 0.158072ms STATS: Query: /child::site/child::people/child::person[ child::phone or child::homepage ]/child::name STATS: Automaton: -STATS: evaluating query: 173.998833ms -STATS: serializing results: 5.010128ms +STATS: 236309 nodes over 254301 were skipped in iteration 0 (92.92 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 140.325069ms +STATS: serializing results: 4.892111ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1728 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1257 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1927, used: 199, occupation: 0.103269 +STATS: cache4: length: 1420, used: 163, occupation: 0.114789 Diff: ok ------------------------------------------- Query: A8 : /site/people/person[address and (phone or homepage) and (creditcard or profile)]/name -STATS: parsing xml document: 187.579155ms -STATS: parsing XPath query: 0.128984ms -STATS: compiling XPath query: 0.154018ms +STATS: parsing xml document: 186.979055ms +STATS: parsing XPath query: 0.118971ms +STATS: compiling XPath query: 0.159979ms STATS: Query: /child::site/child::people/child::person[ child::address and (child::phone or child::homepage) and (child::creditcard or child::profile) ]/child::name STATS: Automaton: -STATS: evaluating query: 184.761047ms -STATS: serializing results: 2.974033ms +STATS: 236309 nodes over 254301 were skipped in iteration 0 (92.92 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 150.840998ms +STATS: serializing results: 3.206968ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 9331 entries +STATS: automaton 0, cache2: 0 entries, cache6: 7979 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 10253, used: 922, occupation: 0.089925 +STATS: cache4: length: 8812, used: 833, occupation: 0.094530 Diff: ok ------------------------------------------- Query: B1 : /site/regions/*/item[parent::namerica or parent::samerica]/name -STATS: parsing xml document: 185.950041ms +STATS: parsing xml document: 191.373110ms STATS: parsing XPath query: 0.096083ms -STATS: compiling XPath query: 0.181913ms +STATS: compiling XPath query: 0.161171ms STATS: Query: /child::site/child::regions/child::*/child::item[ parent::namerica or parent::samerica ]/child::name STATS: Automaton: -STATS: evaluating query: 120.198965ms -STATS: serializing results: 3.969908ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 119.151115ms +STATS: serializing results: 3.636837ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 3466 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -125,27 +148,32 @@ STATS: cache4: length: 3760, used: 294, occupation: 0.078191 Diff: ok ------------------------------------------- Query: B2 : //keyword/ancestor::listitem/text/keyword -STATS: parsing xml document: 194.061995ms -STATS: parsing XPath query: 0.072956ms -STATS: compiling XPath query: 0.154972ms +STATS: parsing xml document: 191.718102ms +STATS: parsing XPath query: 0.073195ms +STATS: compiling XPath query: 0.213861ms STATS: Query: /descendant-or-self::node()/child::keyword/ancestor::listitem/child::text/child::keyword STATS: Automaton: -STATS: evaluating query: 195.713997ms -STATS: serializing results: 13.200998ms +STATS: 210583 nodes over 254301 were skipped in iteration 0 (82.81 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 166.561127ms +STATS: serializing results: 13.072968ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 2331 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1811 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 2619, used: 288, occupation: 0.109966 +STATS: cache4: length: 2050, used: 239, occupation: 0.116585 Diff: ok ------------------------------------------- Query: B3 : /site/open_auctions/open_auction/bidder[following-sibling::bidder] -STATS: parsing xml document: 186.101913ms -STATS: parsing XPath query: 0.073910ms -STATS: compiling XPath query: 0.119925ms +STATS: parsing xml document: 191.766024ms +STATS: parsing XPath query: 0.077009ms +STATS: compiling XPath query: 0.133991ms STATS: Query: /child::site/child::open_auctions/child::open_auction/child::bidder[ following-sibling::bidder ] STATS: Automaton: -STATS: evaluating query: 126.576900ms -STATS: serializing results: 31.543016ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 130.250931ms +STATS: serializing results: 31.550884ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 2871 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -153,13 +181,15 @@ STATS: cache4: length: 3131, used: 260, occupation: 0.083041 Diff: ok ------------------------------------------- Query: B4 : /site/open_auctions/open_auction/bidder[preceding-sibling::bidder] -STATS: parsing xml document: 194.361925ms -STATS: parsing XPath query: 0.109196ms -STATS: compiling XPath query: 0.155210ms +STATS: parsing xml document: 189.858913ms +STATS: parsing XPath query: 0.082970ms +STATS: compiling XPath query: 0.122070ms STATS: Query: /child::site/child::open_auctions/child::open_auction/child::bidder[ preceding-sibling::bidder ] STATS: Automaton: -STATS: evaluating query: 125.017166ms -STATS: serializing results: 31.688929ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 117.531061ms +STATS: serializing results: 31.703949ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 2282 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -167,27 +197,32 @@ STATS: cache4: length: 2507, used: 225, occupation: 0.089749 Diff: ok ------------------------------------------- Query: B5 : /site/regions/*/item[following::item]/name -STATS: parsing xml document: 186.882973ms -STATS: parsing XPath query: 0.083208ms -STATS: compiling XPath query: 0.190973ms +STATS: parsing xml document: 186.423779ms +STATS: parsing XPath query: 0.076056ms +STATS: compiling XPath query: 0.211000ms STATS: Query: /child::site/child::regions/child::*/child::item[ ancestor-or-self::node()/following-sibling::node()/descendant-or-self::item ]/child::name STATS: Automaton: -STATS: evaluating query: 191.325903ms -STATS: serializing results: 5.614042ms +STATS: 1 nodes over 254301 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 200.829983ms +STATS: serializing results: 5.727053ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1992 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1990 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 2302, used: 310, occupation: 0.134666 +STATS: cache4: length: 2299, used: 309, occupation: 0.134406 Diff: ok ------------------------------------------- Query: B6 : /site/regions/*/item[preceding::item]/name -STATS: parsing xml document: 188.734055ms -STATS: parsing XPath query: 0.086069ms -STATS: compiling XPath query: 0.185966ms +STATS: parsing xml document: 187.946081ms +STATS: parsing XPath query: 0.046968ms +STATS: compiling XPath query: 0.171900ms STATS: Query: /child::site/child::regions/child::*/child::item[ ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::item ]/child::name STATS: Automaton: -STATS: evaluating query: 142.535925ms -STATS: serializing results: 5.680084ms +STATS: 254301 nodes over 254301 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 140.237093ms +STATS: serializing results: 5.573988ms +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 170 entries, cache6: 4419 entries STATS: cache2: length: 255, used: 85, occupation: 0.333333 @@ -195,100 +230,130 @@ STATS: cache4: length: 4800, used: 381, occupation: 0.079375 Diff: ok ------------------------------------------- Query: B7 : //person[profile/@income]/name -STATS: parsing xml document: 188.699961ms -STATS: parsing XPath query: 0.071049ms -STATS: compiling XPath query: 0.110149ms +STATS: parsing xml document: 192.195177ms +STATS: parsing XPath query: 0.074148ms +STATS: compiling XPath query: 0.116110ms STATS: Query: /descendant-or-self::node()/child::person[ child::profile/attribute::@income ]/child::name STATS: Automaton: -STATS: evaluating query: 186.697960ms -STATS: serializing results: 3.955126ms +STATS: 236309 nodes over 254301 were skipped in iteration 0 (92.92 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 145.928860ms +STATS: serializing results: 4.064083ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1238 entries +STATS: automaton 0, cache2: 0 entries, cache6: 624 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1349, used: 111, occupation: 0.082283 +STATS: cache4: length: 705, used: 81, occupation: 0.114894 Diff: ok ------------------------------------------- Query: B8 : /site/open_auctions/open_auction[bidder and not(bidder/preceding-sibling::bidder)]/interval -STATS: parsing xml document: 189.706087ms -STATS: parsing XPath query: 0.092983ms -STATS: compiling XPath query: 0.133991ms +STATS: parsing xml document: 189.630985ms +STATS: parsing XPath query: 0.108004ms +STATS: compiling XPath query: 0.137091ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ child::bidder and not(child::bidder/preceding-sibling::bidder) ]/child::interval STATS: Automaton: -STATS: evaluating query: 180.305958ms -STATS: serializing results: 2.574921ms +STATS: 235063 nodes over 254301 were skipped in iteration 0 (92.43 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 140.723944ms +STATS: serializing results: 2.576828ms +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1052 entries +STATS: automaton 0, cache2: 0 entries, cache6: 368 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1229, used: 177, occupation: 0.144020 +STATS: cache4: length: 506, used: 138, occupation: 0.272727 Diff: ok ------------------------------------------- Query: B9 : /site/open_auctions/open_auction[(not(bidder/following::bidder) or not(bidder/preceding::bidder)) or (bidder/following::bidder and bidder/preceding::bidder)]/interval -STATS: parsing xml document: 187.867165ms -STATS: parsing XPath query: 0.136137ms -STATS: compiling XPath query: 0.380993ms +STATS: parsing xml document: 180.969000ms +STATS: parsing XPath query: 0.151157ms +STATS: compiling XPath query: 0.355959ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ not(child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder) or not(child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder) or child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder and child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder ]/child::interval STATS: Automaton: -STATS: evaluating query: 265.134096ms -STATS: serializing results: 6.505966ms +STATS: 1 nodes over 254301 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 251143 nodes over 254301 were skipped in iteration 1 (98.76 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false +STATS: evaluating query: 224.873066ms +STATS: serializing results: 6.433010ms +STATS: 254301 nodes over 254301 were skipped in iteration 3 (100.00 %), redo is: false STATS: 3 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 786 entries +STATS: automaton 0, cache2: 0 entries, cache6: 157 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 976, used: 190, occupation: 0.194672 +STATS: cache4: length: 213, used: 56, occupation: 0.262911 Diff: ok ------------------------------------------- Query: B10 : /site/open_auctions/open_auction[(not(bidder/following::bidder) or not(bidder/preceding::bidder)) and (bidder/following::bidder and bidder/preceding::bidder)]/interval -STATS: parsing xml document: 188.634157ms -STATS: parsing XPath query: 0.128031ms -STATS: compiling XPath query: 0.365973ms +STATS: parsing xml document: 183.919191ms +STATS: parsing XPath query: 0.127792ms +STATS: compiling XPath query: 0.363827ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ (not(child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder) or not(child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder)) and child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder and child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder ]/child::interval STATS: Automaton: -STATS: evaluating query: 254.701853ms -STATS: serializing results: 1.600981ms +STATS: 1 nodes over 254301 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 251143 nodes over 254301 were skipped in iteration 1 (98.76 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 2 (100.00 %), redo is: false +STATS: evaluating query: 221.321106ms +STATS: serializing results: 1.529217ms +STATS: 254301 nodes over 254301 were skipped in iteration 3 (100.00 %), redo is: false STATS: 3 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 827 entries +STATS: automaton 0, cache2: 0 entries, cache6: 153 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1000, used: 173, occupation: 0.173000 +STATS: cache4: length: 208, used: 55, occupation: 0.264423 Diff: ok ------------------------------------------- Query: B11 : //open_auction/bidder/../bidder/../bidder/../interval -STATS: parsing xml document: 189.094067ms -STATS: parsing XPath query: 0.064850ms -STATS: compiling XPath query: 0.294924ms +STATS: parsing xml document: 190.995932ms +STATS: parsing XPath query: 0.072956ms +STATS: compiling XPath query: 0.244856ms STATS: Query: /descendant-or-self::node()/child::open_auction/child::bidder/parent::node()/child::bidder/parent::node()/child::bidder/parent::node()/child::interval STATS: Automaton: -STATS: evaluating query: 303.856134ms -STATS: serializing results: 6.079912ms +STATS: 0 nodes over 254301 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 236211 nodes over 254301 were skipped in iteration 1 (92.89 %), redo is: true +STATS: 236211 nodes over 254301 were skipped in iteration 2 (92.89 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 3 (100.00 %), redo is: false +STATS: evaluating query: 225.605011ms +STATS: serializing results: 6.007910ms +STATS: 254301 nodes over 254301 were skipped in iteration 4 (100.00 %), redo is: false STATS: 4 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 598 entries +STATS: automaton 0, cache2: 0 entries, cache6: 144 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 708, used: 110, occupation: 0.155367 +STATS: cache4: length: 209, used: 65, occupation: 0.311005 Diff: ok ------------------------------------------- Query: B12 : //item/@id/../@id/../@id/../@id/../name -STATS: parsing xml document: 190.536976ms -STATS: parsing XPath query: 0.071049ms +STATS: parsing xml document: 194.081068ms +STATS: parsing XPath query: 0.083923ms STATS: compiling XPath query: 0.293016ms STATS: Query: /descendant-or-self::node()/child::item/attribute::@id/parent::node()/attribute::@id/parent::node()/attribute::@id/parent::node()/attribute::@id/parent::node()/child::name STATS: Automaton: -STATS: evaluating query: 360.573053ms -STATS: serializing results: 5.623817ms +STATS: 0 nodes over 254301 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 188718 nodes over 254301 were skipped in iteration 1 (74.21 %), redo is: true +STATS: 188718 nodes over 254301 were skipped in iteration 2 (74.21 %), redo is: true +STATS: 188718 nodes over 254301 were skipped in iteration 3 (74.21 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 4 (100.00 %), redo is: false +STATS: evaluating query: 266.115189ms +STATS: serializing results: 5.604982ms +STATS: 254301 nodes over 254301 were skipped in iteration 5 (100.00 %), redo is: false STATS: 5 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 870 entries +STATS: automaton 0, cache2: 0 entries, cache6: 416 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 993, used: 123, occupation: 0.123867 +STATS: cache4: length: 524, used: 108, occupation: 0.206107 Diff: ok ------------------------------------------- Query: B13 : //keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword -STATS: parsing xml document: 190.907001ms -STATS: parsing XPath query: 0.097990ms -STATS: compiling XPath query: 0.226021ms +STATS: parsing xml document: 183.907986ms +STATS: parsing XPath query: 0.083923ms +STATS: compiling XPath query: 0.251055ms STATS: Query: /descendant-or-self::node()/child::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword STATS: Automaton: -STATS: evaluating query: 307.029963ms -STATS: serializing results: 14.356136ms +STATS: 203073 nodes over 254301 were skipped in iteration 0 (79.86 %), redo is: true +STATS: 208107 nodes over 254301 were skipped in iteration 1 (81.83 %), redo is: true +STATS: 208107 nodes over 254301 were skipped in iteration 2 (81.83 %), redo is: true +STATS: 254301 nodes over 254301 were skipped in iteration 3 (100.00 %), redo is: false +STATS: evaluating query: 197.850943ms +STATS: serializing results: 14.370203ms +STATS: 254301 nodes over 254301 were skipped in iteration 4 (100.00 %), redo is: false STATS: 4 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 2671 entries +STATS: automaton 0, cache2: 0 entries, cache6: 981 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 2984, used: 313, occupation: 0.104893 +STATS: cache4: length: 1198, used: 217, occupation: 0.181135 Diff: ok ------------------------------------------- diff --git a/tests/xmark_tiny.xml.summary b/tests/xmark_tiny.xml.summary index 708638c..234109f 100644 --- a/tests/xmark_tiny.xml.summary +++ b/tests/xmark_tiny.xml.summary @@ -1,11 +1,13 @@ Query: A1 : /site/closed_auctions/closed_auction/annotation/description/text/keyword -STATS: parsing xml document: 1.966953ms -STATS: parsing XPath query: 0.097990ms -STATS: compiling XPath query: 0.623941ms +STATS: parsing xml document: 1.941919ms +STATS: parsing XPath query: 0.118971ms +STATS: compiling XPath query: 0.624895ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction/child::annotation/child::description/child::text/child::keyword STATS: Automaton: -STATS: evaluating query: 12.537956ms -STATS: serializing results: 1.646042ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 13.736010ms +STATS: serializing results: 1.666784ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 2831 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -13,13 +15,15 @@ STATS: cache4: length: 3099, used: 268, occupation: 0.086480 Diff: ok ------------------------------------------- Query: A2 : //closed_auction//keyword -STATS: parsing xml document: 1.951933ms -STATS: parsing XPath query: 0.050783ms +STATS: parsing xml document: 1.976013ms +STATS: parsing XPath query: 0.051975ms STATS: compiling XPath query: 0.267982ms STATS: Query: /descendant-or-self::node()/child::closed_auction/descendant-or-self::node()/child::keyword STATS: Automaton: -STATS: evaluating query: 4.580975ms -STATS: serializing results: 1.560926ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 7.214785ms +STATS: serializing results: 1.543045ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 2253 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -27,13 +31,15 @@ STATS: cache4: length: 2452, used: 199, occupation: 0.081158 Diff: ok ------------------------------------------- Query: A3 : /site/closed_auctions/closed_auction//keyword -STATS: parsing xml document: 1.996994ms -STATS: parsing XPath query: 0.069141ms -STATS: compiling XPath query: 0.376940ms +STATS: parsing xml document: 1.937866ms +STATS: parsing XPath query: 0.067949ms +STATS: compiling XPath query: 0.401974ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction/descendant-or-self::node()/child::keyword STATS: Automaton: -STATS: evaluating query: 8.721828ms -STATS: serializing results: 1.688957ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 8.767843ms +STATS: serializing results: 1.557112ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 2969 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -41,83 +47,100 @@ STATS: cache4: length: 3212, used: 243, occupation: 0.075654 Diff: ok ------------------------------------------- Query: A4 : /site/closed_auctions/closed_auction[annotation/description/text/keyword]/date -STATS: parsing xml document: 1.893997ms -STATS: parsing XPath query: 0.159025ms -STATS: compiling XPath query: 0.347853ms +STATS: parsing xml document: 2.266884ms +STATS: parsing XPath query: 0.097036ms +STATS: compiling XPath query: 0.423908ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction[ child::annotation/child::description/child::text/child::keyword ]/child::date STATS: Automaton: -STATS: evaluating query: 10.576963ms -STATS: serializing results: 1.627207ms +STATS: 1046 nodes over 1155 were skipped in iteration 0 (90.56 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 13.612032ms +STATS: serializing results: 1.475811ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1056 entries +STATS: automaton 0, cache2: 0 entries, cache6: 269 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1197, used: 141, occupation: 0.117794 +STATS: cache4: length: 341, used: 72, occupation: 0.211144 Diff: ok ------------------------------------------- Query: A5 : /site/closed_auctions/closed_auction[descendant::keyword]/date -STATS: parsing xml document: 1.942873ms -STATS: parsing XPath query: 0.073910ms -STATS: compiling XPath query: 0.401020ms +STATS: parsing xml document: 1.949072ms +STATS: parsing XPath query: 0.077963ms +STATS: compiling XPath query: 0.340939ms STATS: Query: /child::site/child::closed_auctions/child::closed_auction[ descendant::keyword ]/child::date STATS: Automaton: -STATS: evaluating query: 9.468079ms -STATS: serializing results: 1.677036ms +STATS: 1046 nodes over 1155 were skipped in iteration 0 (90.56 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 8.916855ms +STATS: serializing results: 1.583099ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 955 entries +STATS: automaton 0, cache2: 0 entries, cache6: 201 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1080, used: 125, occupation: 0.115741 +STATS: cache4: length: 274, used: 73, occupation: 0.266423 Diff: ok ------------------------------------------- Query: A6 : /site/people/person[profile/gender and profile/age]/name -STATS: parsing xml document: 2.070189ms -STATS: parsing XPath query: 0.130177ms -STATS: compiling XPath query: 0.447989ms +STATS: parsing xml document: 1.895189ms +STATS: parsing XPath query: 0.103951ms +STATS: compiling XPath query: 0.425816ms STATS: Query: /child::site/child::people/child::person[ child::profile/child::gender and child::profile/child::age ]/child::name STATS: Automaton: -STATS: evaluating query: 10.710001ms -STATS: serializing results: 1.626015ms +STATS: 1129 nodes over 1155 were skipped in iteration 0 (97.75 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 10.172129ms +STATS: serializing results: 3.078938ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 224 entries +STATS: automaton 0, cache2: 0 entries, cache6: 66 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 277, used: 53, occupation: 0.191336 +STATS: cache4: length: 95, used: 29, occupation: 0.305263 Diff: ok ------------------------------------------- Query: A7 : /site/people/person[phone or homepage]/name -STATS: parsing xml document: 1.904011ms -STATS: parsing XPath query: 0.080109ms -STATS: compiling XPath query: 0.352859ms +STATS: parsing xml document: 1.924038ms +STATS: parsing XPath query: 0.078917ms +STATS: compiling XPath query: 0.349045ms STATS: Query: /child::site/child::people/child::person[ child::phone or child::homepage ]/child::name STATS: Automaton: -STATS: evaluating query: 9.690046ms -STATS: serializing results: 1.545191ms +STATS: 1129 nodes over 1155 were skipped in iteration 0 (97.75 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 8.696079ms +STATS: serializing results: 1.600027ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 390 entries +STATS: automaton 0, cache2: 0 entries, cache6: 88 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 476, used: 86, occupation: 0.180672 +STATS: cache4: length: 140, used: 52, occupation: 0.371429 Diff: ok ------------------------------------------- Query: A8 : /site/people/person[address and (phone or homepage) and (creditcard or profile)]/name -STATS: parsing xml document: 2.023935ms -STATS: parsing XPath query: 0.114202ms -STATS: compiling XPath query: 0.465155ms +STATS: parsing xml document: 1.899004ms +STATS: parsing XPath query: 0.114918ms +STATS: compiling XPath query: 0.459909ms STATS: Query: /child::site/child::people/child::person[ child::address and (child::phone or child::homepage) and (child::creditcard or child::profile) ]/child::name STATS: Automaton: -STATS: evaluating query: 12.446880ms -STATS: serializing results: 1.468897ms +STATS: 1129 nodes over 1155 were skipped in iteration 0 (97.75 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 11.929989ms +STATS: serializing results: 1.475811ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 447 entries +STATS: automaton 0, cache2: 0 entries, cache6: 92 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 524, used: 77, occupation: 0.146947 +STATS: cache4: length: 139, used: 47, occupation: 0.338129 Diff: ok ------------------------------------------- Query: B1 : /site/regions/*/item[parent::namerica or parent::samerica]/name -STATS: parsing xml document: 1.977921ms -STATS: parsing XPath query: 0.088215ms -STATS: compiling XPath query: 0.484943ms +STATS: parsing xml document: 2.445936ms +STATS: parsing XPath query: 0.091076ms +STATS: compiling XPath query: 0.488997ms STATS: Query: /child::site/child::regions/child::*/child::item[ parent::namerica or parent::samerica ]/child::name STATS: Automaton: -STATS: evaluating query: 12.034893ms -STATS: serializing results: 1.737118ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 8.671999ms +STATS: serializing results: 1.447201ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 2553 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -125,27 +148,32 @@ STATS: cache4: length: 2784, used: 231, occupation: 0.082974 Diff: ok ------------------------------------------- Query: B2 : //keyword/ancestor::listitem/text/keyword -STATS: parsing xml document: 1.939058ms -STATS: parsing XPath query: 0.074148ms -STATS: compiling XPath query: 0.350237ms +STATS: parsing xml document: 1.924992ms +STATS: parsing XPath query: 0.075102ms +STATS: compiling XPath query: 0.345945ms STATS: Query: /descendant-or-self::node()/child::keyword/ancestor::listitem/child::text/child::keyword STATS: Automaton: -STATS: evaluating query: 7.805109ms -STATS: serializing results: 1.803875ms +STATS: 838 nodes over 1155 were skipped in iteration 0 (72.55 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 11.610985ms +STATS: serializing results: 1.956940ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1419 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1079 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1595, used: 176, occupation: 0.110345 +STATS: cache4: length: 1225, used: 146, occupation: 0.119184 Diff: ok ------------------------------------------- Query: B3 : /site/open_auctions/open_auction/bidder[following-sibling::bidder] -STATS: parsing xml document: 1.926184ms -STATS: parsing XPath query: 0.070095ms -STATS: compiling XPath query: 0.368118ms +STATS: parsing xml document: 1.966000ms +STATS: parsing XPath query: 0.071049ms +STATS: compiling XPath query: 0.307083ms STATS: Query: /child::site/child::open_auctions/child::open_auction/child::bidder[ following-sibling::bidder ] STATS: Automaton: -STATS: evaluating query: 7.315159ms -STATS: serializing results: 2.036095ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 7.487059ms +STATS: serializing results: 1.948833ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 2328 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -153,13 +181,15 @@ STATS: cache4: length: 2549, used: 221, occupation: 0.086701 Diff: ok ------------------------------------------- Query: B4 : /site/open_auctions/open_auction/bidder[preceding-sibling::bidder] -STATS: parsing xml document: 2.146959ms -STATS: parsing XPath query: 0.077963ms -STATS: compiling XPath query: 0.306129ms +STATS: parsing xml document: 1.992941ms +STATS: parsing XPath query: 0.087023ms +STATS: compiling XPath query: 0.313997ms STATS: Query: /child::site/child::open_auctions/child::open_auction/child::bidder[ preceding-sibling::bidder ] STATS: Automaton: -STATS: evaluating query: 6.942987ms -STATS: serializing results: 1.972914ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 7.298946ms +STATS: serializing results: 2.054930ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 1951 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -167,27 +197,32 @@ STATS: cache4: length: 2138, used: 187, occupation: 0.087465 Diff: ok ------------------------------------------- Query: B5 : /site/regions/*/item[following::item]/name -STATS: parsing xml document: 2.192020ms -STATS: parsing XPath query: 0.087023ms -STATS: compiling XPath query: 0.604153ms +STATS: parsing xml document: 1.929998ms +STATS: parsing XPath query: 0.079155ms +STATS: compiling XPath query: 0.583172ms STATS: Query: /child::site/child::regions/child::*/child::item[ ancestor-or-self::node()/following-sibling::node()/descendant-or-self::item ]/child::name STATS: Automaton: -STATS: evaluating query: 13.622046ms -STATS: serializing results: 1.582861ms +STATS: 1 nodes over 1155 were skipped in iteration 0 (0.09 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 15.670061ms +STATS: serializing results: 1.724005ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1374 entries +STATS: automaton 0, cache2: 0 entries, cache6: 1372 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1627, used: 253, occupation: 0.155501 +STATS: cache4: length: 1624, used: 252, occupation: 0.155172 Diff: ok ------------------------------------------- Query: B6 : /site/regions/*/item[preceding::item]/name -STATS: parsing xml document: 1.945019ms -STATS: parsing XPath query: 0.077963ms -STATS: compiling XPath query: 0.524998ms +STATS: parsing xml document: 2.002954ms +STATS: parsing XPath query: 0.078917ms +STATS: compiling XPath query: 0.535965ms STATS: Query: /child::site/child::regions/child::*/child::item[ ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::item ]/child::name STATS: Automaton: -STATS: evaluating query: 14.191866ms -STATS: serializing results: 1.636028ms +STATS: 1155 nodes over 1155 were skipped in iteration 0 (100.00 %), redo is: false +STATS: evaluating query: 14.605999ms +STATS: serializing results: 1.614094ms +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false STATS: 1 iterations STATS: automaton 0, cache2: 140 entries, cache6: 3069 entries STATS: cache2: length: 210, used: 70, occupation: 0.333333 @@ -195,100 +230,128 @@ STATS: cache4: length: 3392, used: 323, occupation: 0.095224 Diff: ok ------------------------------------------- Query: B7 : //person[profile/@income]/name -STATS: parsing xml document: 1.955032ms -STATS: parsing XPath query: 0.075102ms -STATS: compiling XPath query: 0.281096ms +STATS: parsing xml document: 1.917839ms +STATS: parsing XPath query: 0.077963ms +STATS: compiling XPath query: 0.272036ms STATS: Query: /descendant-or-self::node()/child::person[ child::profile/attribute::@income ]/child::name STATS: Automaton: -STATS: evaluating query: 7.355928ms -STATS: serializing results: 1.435995ms +STATS: 1129 nodes over 1155 were skipped in iteration 0 (97.75 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 3.632784ms +STATS: serializing results: 1.396894ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 284 entries +STATS: automaton 0, cache2: 0 entries, cache6: 58 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 328, used: 44, occupation: 0.134146 +STATS: cache4: length: 84, used: 26, occupation: 0.309524 Diff: ok ------------------------------------------- Query: B8 : /site/open_auctions/open_auction[bidder and not(bidder/preceding-sibling::bidder)]/interval -STATS: parsing xml document: 1.937151ms -STATS: parsing XPath query: 0.100136ms -STATS: compiling XPath query: 0.396013ms +STATS: parsing xml document: 1.998901ms +STATS: parsing XPath query: 0.102043ms +STATS: compiling XPath query: 0.397921ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ child::bidder and not(child::bidder/preceding-sibling::bidder) ]/child::interval STATS: Automaton: -STATS: evaluating query: 10.786057ms -STATS: serializing results: 1.598120ms +STATS: 1091 nodes over 1155 were skipped in iteration 0 (94.46 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 10.616779ms +STATS: serializing results: 1.590967ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 566 entries +STATS: automaton 0, cache2: 0 entries, cache6: 124 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 660, used: 94, occupation: 0.142424 +STATS: cache4: length: 184, used: 60, occupation: 0.326087 Diff: ok ------------------------------------------- Query: B9 : /site/open_auctions/open_auction[(not(bidder/following::bidder) or not(bidder/preceding::bidder)) or (bidder/following::bidder and bidder/preceding::bidder)]/interval -STATS: parsing xml document: 2.006054ms -STATS: parsing XPath query: 0.141144ms -STATS: compiling XPath query: 1.159906ms +STATS: parsing xml document: 1.937151ms +STATS: parsing XPath query: 0.144005ms +STATS: compiling XPath query: 1.156092ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ not(child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder) or not(child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder) or child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder and child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder ]/child::interval STATS: Automaton: -STATS: evaluating query: 18.238068ms -STATS: serializing results: 1.686096ms +STATS: 1 nodes over 1155 were skipped in iteration 0 (0.09 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 18.059015ms +STATS: serializing results: 1.640081ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 979 entries +STATS: automaton 0, cache2: 0 entries, cache6: 977 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1253, used: 274, occupation: 0.218675 +STATS: cache4: length: 1250, used: 273, occupation: 0.218400 Diff: ok ------------------------------------------- Query: B10 : /site/open_auctions/open_auction[(not(bidder/following::bidder) or not(bidder/preceding::bidder)) and (bidder/following::bidder and bidder/preceding::bidder)]/interval -STATS: parsing xml document: 1.948833ms -STATS: parsing XPath query: 0.134945ms -STATS: compiling XPath query: 1.168966ms +STATS: parsing xml document: 1.865864ms +STATS: parsing XPath query: 0.143051ms +STATS: compiling XPath query: 1.295090ms STATS: Query: /child::site/child::open_auctions/child::open_auction[ (not(child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder) or not(child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder)) and child::bidder/ancestor-or-self::node()/following-sibling::node()/descendant-or-self::bidder and child::bidder/ancestor-or-self::node()/preceding-sibling::node()/descendant-or-self::bidder ]/child::interval STATS: Automaton: -STATS: evaluating query: 21.468163ms -STATS: serializing results: 1.615047ms +STATS: 1 nodes over 1155 were skipped in iteration 0 (0.09 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 1 (100.00 %), redo is: false +STATS: evaluating query: 27.679920ms +STATS: serializing results: 1.658916ms +STATS: 1155 nodes over 1155 were skipped in iteration 2 (100.00 %), redo is: false STATS: 2 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 980 entries +STATS: automaton 0, cache2: 0 entries, cache6: 978 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1250, used: 270, occupation: 0.216000 +STATS: cache4: length: 1247, used: 269, occupation: 0.215718 Diff: ok ------------------------------------------- Query: B11 : //open_auction/bidder/../bidder/../bidder/../interval -STATS: parsing xml document: 1.931906ms -STATS: parsing XPath query: 0.066042ms -STATS: compiling XPath query: 0.644922ms +STATS: parsing xml document: 1.846075ms +STATS: parsing XPath query: 0.068903ms +STATS: compiling XPath query: 0.643015ms STATS: Query: /descendant-or-self::node()/child::open_auction/child::bidder/parent::node()/child::bidder/parent::node()/child::bidder/parent::node()/child::interval STATS: Automaton: -STATS: evaluating query: 15.552044ms -STATS: serializing results: 1.615047ms +STATS: 0 nodes over 1155 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 1091 nodes over 1155 were skipped in iteration 1 (94.46 %), redo is: true +STATS: 1091 nodes over 1155 were skipped in iteration 2 (94.46 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 3 (100.00 %), redo is: false +STATS: evaluating query: 18.645048ms +STATS: serializing results: 1.463175ms +STATS: 1155 nodes over 1155 were skipped in iteration 4 (100.00 %), redo is: false STATS: 4 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 479 entries +STATS: automaton 0, cache2: 0 entries, cache6: 93 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 563, used: 84, occupation: 0.149201 +STATS: cache4: length: 149, used: 56, occupation: 0.375839 Diff: ok ------------------------------------------- Query: B12 : //item/@id/../@id/../@id/../@id/../name -STATS: parsing xml document: 1.978874ms -STATS: parsing XPath query: 0.072956ms -STATS: compiling XPath query: 0.880957ms +STATS: parsing xml document: 1.981020ms +STATS: parsing XPath query: 0.072002ms +STATS: compiling XPath query: 0.829935ms STATS: Query: /descendant-or-self::node()/child::item/attribute::@id/parent::node()/attribute::@id/parent::node()/attribute::@id/parent::node()/attribute::@id/parent::node()/child::name STATS: Automaton: -STATS: evaluating query: 19.575119ms -STATS: serializing results: 1.701117ms +STATS: 0 nodes over 1155 were skipped in iteration 0 (0.00 %), redo is: true +STATS: 891 nodes over 1155 were skipped in iteration 1 (77.14 %), redo is: true +STATS: 891 nodes over 1155 were skipped in iteration 2 (77.14 %), redo is: true +STATS: 891 nodes over 1155 were skipped in iteration 3 (77.14 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 4 (100.00 %), redo is: false +STATS: evaluating query: 20.490885ms +STATS: serializing results: 1.349926ms +STATS: 1155 nodes over 1155 were skipped in iteration 5 (100.00 %), redo is: false STATS: 5 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 725 entries +STATS: automaton 0, cache2: 0 entries, cache6: 304 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 820, used: 95, occupation: 0.115854 +STATS: cache4: length: 384, used: 80, occupation: 0.208333 Diff: ok ------------------------------------------- Query: B13 : //keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword -STATS: parsing xml document: 1.997948ms -STATS: parsing XPath query: 0.092983ms -STATS: compiling XPath query: 0.646114ms +STATS: parsing xml document: 1.920938ms +STATS: parsing XPath query: 0.090837ms +STATS: compiling XPath query: 0.641108ms STATS: Query: /descendant-or-self::node()/child::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword/ancestor::parlist/descendant::keyword STATS: Automaton: -STATS: evaluating query: 16.010046ms -STATS: serializing results: 1.931906ms +STATS: 798 nodes over 1155 were skipped in iteration 0 (69.09 %), redo is: true +STATS: 798 nodes over 1155 were skipped in iteration 1 (69.09 %), redo is: true +STATS: 798 nodes over 1155 were skipped in iteration 2 (69.09 %), redo is: true +STATS: 1155 nodes over 1155 were skipped in iteration 3 (100.00 %), redo is: false +STATS: evaluating query: 24.297953ms +STATS: serializing results: 1.913071ms +STATS: 1155 nodes over 1155 were skipped in iteration 4 (100.00 %), redo is: false STATS: 4 iterations -STATS: automaton 0, cache2: 0 entries, cache6: 1491 entries +STATS: automaton 0, cache2: 0 entries, cache6: 660 entries STATS: cache2: length: 0, used: 0, occupation: -nan -STATS: cache4: length: 1702, used: 211, occupation: 0.123972 +STATS: cache4: length: 817, used: 157, occupation: 0.192166 Diff: ok ------------------------------------------- -- 2.17.1