projects / tatoo.git / blobdiff
? search:
summary | shortlog | log | commit | commitdiff | tree
raw | inline | side by side
Add a clean logger infrastructure.
[tatoo.git] / tests / alphabet.xml.summary
diff --git a/tests/alphabet.xml.summary b/tests/alphabet.xml.summary
index cc9ae7d..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.199080ms
-STATS: parsing XPath query: 0.056028ms
-STATS: compiling XPath query: 0.133991ms
+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: 0.764132ms
-STATS: serializing results: 1.646996ms
+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.370979ms
-STATS: parsing XPath query: 0.051022ms
-STATS: compiling XPath query: 0.166893ms
+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.008915ms
-STATS: serializing results: 1.794100ms
+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
@@ -28,12 +32,14 @@ Diff: ok
 -------------------------------------------
 Query: A3 : //L/descendant::*
 STATS: parsing xml document: 0.369072ms
-STATS: parsing XPath query: 0.089884ms
-STATS: compiling XPath query: 0.217915ms
+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.200127ms
-STATS: serializing results: 1.621008ms
+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.438929ms
+STATS: parsing xml document: 0.360012ms
 STATS: parsing XPath query: 0.048876ms
-STATS: compiling XPath query: 0.180006ms
+STATS: compiling XPath query: 0.190020ms
 STATS: Query: /descendant-or-self::node()/child::L/descendant-or-self::* 
 STATS: Automaton: 
-STATS: evaluating query: 2.231836ms
-STATS: serializing results: 1.777887ms
+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
@@ -56,12 +64,14 @@ Diff: ok
 -------------------------------------------
 Query: A5 : //L/ancestor::*
 STATS: parsing xml document: 0.365973ms
-STATS: parsing XPath query: 0.051022ms
-STATS: compiling XPath query: 0.172138ms
+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.207994ms
-STATS: serializing results: 2.154827ms
+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.367165ms
-STATS: parsing XPath query: 0.046968ms
-STATS: compiling XPath query: 0.205994ms
+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.345800ms
-STATS: serializing results: 2.530098ms
+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.364780ms
-STATS: parsing XPath query: 0.059128ms
-STATS: compiling XPath query: 0.162125ms
+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.799107ms
-STATS: serializing results: 1.568079ms
+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.370979ms
-STATS: parsing XPath query: 0.053883ms
-STATS: compiling XPath query: 0.162840ms
+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.916885ms
-STATS: serializing results: 4.055023ms
+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.372887ms
+STATS: parsing xml document: 0.361919ms
 STATS: parsing XPath query: 0.051022ms
-STATS: compiling XPath query: 0.334978ms
+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.406069ms
-STATS: serializing results: 1.731873ms
+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.368118ms
-STATS: parsing XPath query: 0.054836ms
-STATS: compiling XPath query: 0.283003ms
+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: 7.886887ms
-STATS: serializing results: 1.865149ms
+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.392914ms
-STATS: parsing XPath query: 0.047922ms
-STATS: compiling XPath query: 0.177145ms
+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.735926ms
-STATS: serializing results: 1.796961ms
+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.378132ms
-STATS: parsing XPath query: 0.059843ms
-STATS: compiling XPath query: 0.287056ms
+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: 2.931833ms
-STATS: serializing results: 1.657963ms
+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.357866ms
-STATS: parsing XPath query: 0.046968ms
-STATS: compiling XPath query: 0.152111ms
+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.730204ms
-STATS: serializing results: 1.868010ms
+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.372171ms
+STATS: parsing xml document: 0.390053ms
 STATS: parsing XPath query: 0.052929ms
-STATS: compiling XPath query: 0.166893ms
+STATS: compiling XPath query: 0.167131ms
 STATS: Query: /descendant-or-self::node()/child::*[ parent::L ] 
 STATS: Automaton: 
-STATS: evaluating query: 1.759052ms
-STATS: serializing results: 1.687050ms
+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.368834ms
-STATS: parsing XPath query: 0.045776ms
-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: 1.796007ms
-STATS: serializing results: 2.280951ms
+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.386953ms
-STATS: parsing XPath query: 0.049829ms
-STATS: compiling XPath query: 0.176907ms
+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.150059ms
-STATS: serializing results: 2.135992ms
+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.374079ms
-STATS: parsing XPath query: 0.050068ms
-STATS: compiling XPath query: 0.192165ms
+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.835823ms
-STATS: serializing results: 1.564980ms
+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.431061ms
-STATS: parsing XPath query: 0.049114ms
-STATS: compiling XPath query: 0.180960ms
+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.905918ms
-STATS: serializing results: 1.775026ms
+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.376940ms
-STATS: parsing XPath query: 0.046015ms
-STATS: compiling XPath query: 0.154972ms
+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.612902ms
-STATS: serializing results: 1.538992ms
+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.437021ms
-STATS: parsing XPath query: 0.058889ms
-STATS: compiling XPath query: 0.155210ms
+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.534939ms
-STATS: serializing results: 1.504898ms
+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.350952ms
-STATS: parsing XPath query: 0.050068ms
-STATS: compiling XPath query: 0.226021ms
+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.453037ms
-STATS: serializing results: 1.742840ms
+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.368118ms
-STATS: parsing XPath query: 0.055075ms
-STATS: compiling XPath query: 0.227928ms
+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.612041ms
-STATS: serializing results: 1.841068ms
+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.166178ms
-STATS: parsing XPath query: 0.030041ms
-STATS: compiling XPath query: 0.080109ms
+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.607967ms
-STATS: serializing results: 1.639128ms
+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.366926ms
-STATS: parsing XPath query: 0.043869ms
-STATS: compiling XPath query: 0.211954ms
+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.461983ms
-STATS: serializing results: 2.345085ms
+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.365973ms
-STATS: parsing XPath query: 0.055075ms
-STATS: compiling XPath query: 0.200987ms
+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.068043ms
-STATS: serializing results: 1.474857ms
+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.478983ms
+STATS: parsing xml document: 0.365973ms
 STATS: parsing XPath query: 0.068903ms
-STATS: compiling XPath query: 0.209093ms
+STATS: compiling XPath query: 0.198841ms
 STATS: Query: /descendant-or-self::node()/child::L/child::comment() 
 STATS: Automaton: 
-STATS: evaluating query: 2.010107ms
-STATS: serializing results: 1.503944ms
+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.419855ms
-STATS: parsing XPath query: 0.075102ms
-STATS: compiling XPath query: 0.198841ms
+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.058029ms
-STATS: serializing results: 1.420975ms
+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.360966ms
-STATS: parsing XPath query: 0.072002ms
-STATS: compiling XPath query: 0.195026ms
+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: 1.106977ms
-STATS: serializing results: 2.144098ms
+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.380993ms
-STATS: parsing XPath query: 0.056028ms
-STATS: compiling XPath query: 0.200033ms
+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.035141ms
-STATS: serializing results: 1.604080ms
+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.368834ms
+STATS: parsing xml document: 0.365973ms
 STATS: parsing XPath query: 0.048161ms
-STATS: compiling XPath query: 0.205040ms
+STATS: compiling XPath query: 0.202894ms
 STATS: Query: /descendant-or-self::node()/child::L/child::N 
 STATS: Automaton: 
-STATS: evaluating query: 2.115011ms
-STATS: serializing results: 1.475811ms
+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.386000ms
-STATS: parsing XPath query: 0.040054ms
-STATS: compiling XPath query: 0.193834ms
+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.058029ms
-STATS: serializing results: 1.773119ms
+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.367880ms
-STATS: parsing XPath query: 0.056028ms
-STATS: compiling XPath query: 0.261068ms
+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.534887ms
-STATS: serializing results: 1.616001ms
+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
@@ -448,12 +514,14 @@ Diff: ok
 -------------------------------------------
 Query: O2 : //*[not(child::*) and preceding::Q]
 STATS: parsing xml document: 0.366926ms
-STATS: parsing XPath query: 0.066042ms
-STATS: compiling XPath query: 0.269890ms
+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.399942ms
-STATS: serializing results: 1.590014ms
+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.382900ms
-STATS: parsing XPath query: 0.059843ms
-STATS: compiling XPath query: 0.327826ms
+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.667086ms
-STATS: serializing results: 2.055883ms
+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.379086ms
-STATS: parsing XPath query: 0.050068ms
-STATS: compiling XPath query: 0.426054ms
+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.055044ms
-STATS: serializing results: 2.132177ms
+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
Tree Automata TOOlkit