Add a clean logger infrastructure.

[tatoo.git] / tests / alphabet.xml.summary

diff --git a/tests/alphabet.xml.summary b/tests/alphabet.xml.summary
index b84f81e..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.375986ms
-STATS: parsing XPath query: 0.036001ms
-STATS: compiling XPath query: 0.203133ms
+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.120018ms
-STATS: serializing results: 1.610041ms
+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.386000ms
-STATS: parsing XPath query: 0.042915ms
-STATS: compiling XPath query: 0.164032ms
+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: 1.954079ms
-STATS: serializing results: 1.950026ms
+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.361919ms
-STATS: parsing XPath query: 0.036955ms
-STATS: compiling XPath query: 0.213861ms
+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.192974ms
-STATS: serializing results: 1.615047ms
+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.368118ms
-STATS: parsing XPath query: 0.087023ms
-STATS: compiling XPath query: 0.189066ms
+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.336025ms
-STATS: serializing results: 1.883030ms
+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.364065ms
-STATS: parsing XPath query: 0.037909ms
-STATS: compiling XPath query: 0.165939ms
+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.583027ms
-STATS: serializing results: 2.183914ms
+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.574827ms
-STATS: parsing XPath query: 0.056028ms
-STATS: compiling XPath query: 0.334024ms
+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: 3.679037ms
-STATS: serializing results: 2.243042ms
+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.149012ms
-STATS: parsing XPath query: 0.021935ms
-STATS: compiling XPath query: 0.066042ms
+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: 0.725985ms
-STATS: serializing results: 1.456976ms
+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.148058ms
-STATS: parsing XPath query: 0.023842ms
-STATS: compiling XPath query: 0.062943ms
+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: 0.781059ms
-STATS: serializing results: 1.357079ms
+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.370979ms
-STATS: parsing XPath query: 0.042915ms
-STATS: compiling XPath query: 0.288963ms
+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.980896ms
-STATS: serializing results: 1.842976ms
+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.371933ms
-STATS: parsing XPath query: 0.046968ms
+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.105993ms
-STATS: serializing results: 1.837969ms
+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.518084ms
-STATS: parsing XPath query: 0.062943ms
-STATS: compiling XPath query: 0.202179ms
+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.765013ms
-STATS: serializing results: 1.644850ms
+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.440121ms
-STATS: parsing XPath query: 0.053883ms
-STATS: compiling XPath query: 0.241041ms
+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.050089ms
-STATS: serializing results: 1.691103ms
+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.403881ms
-STATS: parsing XPath query: 0.046968ms
-STATS: compiling XPath query: 0.208855ms
+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: 2.264977ms
-STATS: serializing results: 1.861095ms
+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.488997ms
-STATS: parsing XPath query: 0.049829ms
-STATS: compiling XPath query: 0.171900ms
+STATS: parsing xml document: 0.390053ms
+STATS: parsing XPath query: 0.052929ms
+STATS: compiling XPath query: 0.167131ms
 STATS: Query: /descendant-or-self::node()/child::*[ parent::L ] 
 STATS: Automaton: 
-STATS: evaluating query: 1.897097ms
-STATS: serializing results: 1.640081ms
+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.370026ms
-STATS: parsing XPath query: 0.042915ms
-STATS: compiling XPath query: 0.175953ms
+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: 1.796007ms
-STATS: serializing results: 2.020121ms
+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.371933ms
-STATS: parsing XPath query: 0.043869ms
-STATS: compiling XPath query: 0.185966ms
+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.321959ms
-STATS: serializing results: 2.125025ms
+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.358820ms
-STATS: parsing XPath query: 0.041962ms
-STATS: compiling XPath query: 0.192881ms
+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.881123ms
-STATS: serializing results: 1.569033ms
+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.365973ms
-STATS: parsing XPath query: 0.043869ms
-STATS: compiling XPath query: 0.189066ms
+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: 2.273083ms
-STATS: serializing results: 1.817942ms
+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 XPath query: 0.044107ms
-STATS: compiling XPath query: 0.164032ms
+STATS: parsing xml document: 0.364065ms
+STATS: parsing XPath query: 0.046968ms
+STATS: compiling XPath query: 0.156879ms
 STATS: Query: /descendant-or-self::node()/child::*[ following-sibling::L ] 
 STATS: Automaton: 
-STATS: evaluating query: 1.653910ms
-STATS: serializing results: 1.550913ms
+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.367880ms
-STATS: parsing XPath query: 0.049114ms
-STATS: compiling XPath query: 0.164986ms
+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.538992ms
-STATS: serializing results: 1.570940ms
+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.445127ms
-STATS: parsing XPath query: 0.042915ms
-STATS: compiling XPath query: 0.234127ms
+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: 7.771015ms
-STATS: serializing results: 1.768112ms
+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.387192ms
-STATS: parsing XPath query: 0.058889ms
-STATS: compiling XPath query: 0.237942ms
+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: 4.338026ms
-STATS: serializing results: 1.936913ms
+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.246048ms
-STATS: parsing XPath query: 0.040054ms
-STATS: compiling XPath query: 0.104904ms
+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: 0.613928ms
-STATS: serializing results: 1.585007ms
+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.401974ms
-STATS: parsing XPath query: 0.066042ms
-STATS: compiling XPath query: 0.286818ms
+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.514912ms
-STATS: serializing results: 2.412796ms
+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.167847ms
-STATS: parsing XPath query: 0.054121ms
+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.181053ms
-STATS: serializing results: 1.456022ms
+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.375986ms
-STATS: parsing XPath query: 0.061035ms
-STATS: compiling XPath query: 0.207901ms
+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.149820ms
-STATS: serializing results: 1.460075ms
+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.547886ms
-STATS: parsing XPath query: 0.077963ms
-STATS: compiling XPath query: 0.247002ms
+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.171040ms
-STATS: serializing results: 1.477957ms
+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.364065ms
-STATS: parsing XPath query: 0.076056ms
-STATS: compiling XPath query: 0.206947ms
+STATS: parsing xml document: 0.367880ms
+STATS: parsing XPath query: 0.077009ms
+STATS: compiling XPath query: 0.201941ms
 STATS: Query: /descendant-or-self::node()/child::L/child::processing-instruction('?myPI') 
 STATS: Automaton: 
-STATS: evaluating query: 2.166033ms
-STATS: serializing results: 1.529932ms
+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.372171ms
-STATS: parsing XPath query: 0.053167ms
-STATS: compiling XPath query: 0.200987ms
+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.104998ms
-STATS: serializing results: 1.624107ms
+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.363827ms
-STATS: parsing XPath query: 0.041962ms
-STATS: compiling XPath query: 0.200987ms
+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.289057ms
-STATS: serializing results: 1.558065ms
+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.360012ms
-STATS: parsing XPath query: 0.042915ms
-STATS: compiling XPath query: 0.295162ms
+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.148151ms
-STATS: serializing results: 1.518011ms
+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.401974ms
-STATS: parsing XPath query: 0.054121ms
-STATS: compiling XPath query: 0.253916ms
+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: 6.214142ms
-STATS: serializing results: 1.968861ms
+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.370026ms
-STATS: parsing XPath query: 0.063896ms
-STATS: compiling XPath query: 0.282049ms
+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.774021ms
-STATS: serializing results: 1.709938ms
+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.369072ms
-STATS: parsing XPath query: 0.078917ms
-STATS: compiling XPath query: 0.324965ms
+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: 11.293888ms
-STATS: serializing results: 2.145052ms
+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.369787ms
-STATS: parsing XPath query: 0.051975ms
-STATS: compiling XPath query: 0.379086ms
+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: 6.983995ms
-STATS: serializing results: 2.542019ms
+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