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.

diff --git a/Remakefile.in b/Remakefile.in
index f5ba98d..3f16f26 100644 (file)
--- 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 (file)
--- a/src/ata.ml
+++ b/src/ata.ml
@@ -14,7 +14,7 @@
 (***********************************************************************)
 
 (*
-  Time-stamp: <Last modified on 2013-04-23 15:12:29 CEST by Kim Nguyen>
+  Time-stamp: <Last modified on 2013-04-24 23:14:46 CEST by Kim Nguyen>
 *)
 
 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 (file)
--- a/src/ata.mli
+++ b/src/ata.mli
@@ -14,7 +14,7 @@
 (***********************************************************************)
 
 (*
-  Time-stamp: <Last modified on 2013-04-23 15:12:15 CEST by Kim Nguyen>
+  Time-stamp: <Last modified on 2013-04-24 23:19:41 CEST by Kim Nguyen>
 *)
 
 type predicate =

diff --git a/src/bitvector.ml b/src/bitvector.ml
new file mode 100644 (file)
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 (file)
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 (file)
--- a/src/eval.ml
+++ b/src/eval.ml
@@ -14,7 +14,7 @@
 (***********************************************************************)
 
 (*
-  Time-stamp: <Last modified on 2013-04-23 15:45:14 CEST by Kim Nguyen>
+  Time-stamp: <Last modified on 2013-04-25 11:20:58 CEST by Kim Nguyen>
 *)
 
 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<br/>sat: %a<br/>unsat: %a<br/>todo: %around: %i<br/>"
+       "node: %i<br/>%s<br/>sat: %a<br/>unsat: %a<br/>todo: %around: %i<br/>"
+       ((T.preorder tree node):>int)
        msg
        StateSet.print config.Ata.sat
        StateSet.print config.Ata.unsat
        (Ata.TransList.print ~sep:"<br/>") 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 (file)
--- 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 (file)
--- 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 (file)
--- 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 (file)
--- 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
 -------------------------------------------