projects / tatoo.git / blobdiff
? search:
summary | shortlog | log | commit | commitdiff | tree
raw | inline | side by side
Add a clean logger infrastructure.
[tatoo.git] / tests / xmark_tiny.xml.summary
diff --git a/tests/xmark_tiny.xml.summary b/tests/xmark_tiny.xml.summary
index 4d8cf96..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.956940ms
-STATS: parsing XPath query: 0.092983ms
-STATS: compiling XPath query: 0.627041ms
+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: 11.539936ms
-STATS: serializing results: 1.766920ms
+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.991987ms
+STATS: parsing xml document: 1.976013ms
 STATS: parsing XPath query: 0.051975ms
-STATS: compiling XPath query: 0.270128ms
+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: 7.020950ms
-STATS: serializing results: 1.558065ms
+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.940966ms
-STATS: parsing XPath query: 0.061989ms
-STATS: compiling XPath query: 0.340939ms
+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.503914ms
-STATS: serializing results: 1.445055ms
+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.902819ms
-STATS: parsing XPath query: 0.120878ms
-STATS: compiling XPath query: 0.432968ms
+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: 13.282061ms
-STATS: serializing results: 1.524925ms
+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.930952ms
-STATS: parsing XPath query: 0.074863ms
-STATS: compiling XPath query: 0.339985ms
+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.056091ms
-STATS: serializing results: 1.557112ms
+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: 1.964808ms
-STATS: parsing XPath query: 0.099897ms
-STATS: compiling XPath query: 0.435829ms
+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.241985ms
-STATS: serializing results: 1.440048ms
+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.909018ms
-STATS: parsing XPath query: 0.079870ms
-STATS: compiling XPath query: 0.353098ms
+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: 8.873940ms
+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: 1.935959ms
-STATS: parsing XPath query: 0.110865ms
-STATS: compiling XPath query: 0.476122ms
+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.123823ms
-STATS: serializing results: 1.512051ms
+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: 2.059937ms
-STATS: parsing XPath query: 0.092983ms
-STATS: compiling XPath query: 0.500917ms
+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.138844ms
-STATS: serializing results: 1.552105ms
+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: 2.015829ms
-STATS: parsing XPath query: 0.092983ms
-STATS: compiling XPath query: 0.349998ms
+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: 12.484074ms
-STATS: serializing results: 1.909971ms
+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.919031ms
-STATS: parsing XPath query: 0.066996ms
-STATS: compiling XPath query: 0.306129ms
+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: 6.998062ms
-STATS: serializing results: 2.038956ms
+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: 1.979113ms
-STATS: parsing XPath query: 0.072002ms
-STATS: compiling XPath query: 0.308037ms
+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.852865ms
-STATS: serializing results: 1.967907ms
+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: 1.950979ms
-STATS: parsing XPath query: 0.069141ms
-STATS: compiling XPath query: 0.543118ms
+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: 12.217999ms
-STATS: serializing results: 1.595974ms
+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: 2.020121ms
-STATS: parsing XPath query: 0.076056ms
-STATS: compiling XPath query: 0.531912ms
+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: 16.092777ms
-STATS: serializing results: 1.388073ms
+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: 2.062798ms
-STATS: parsing XPath query: 0.082016ms
-STATS: compiling XPath query: 0.283003ms
+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: 6.775141ms
-STATS: serializing results: 1.516104ms
+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.899958ms
-STATS: parsing XPath query: 0.092983ms
-STATS: compiling XPath query: 0.430107ms
+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.117054ms
-STATS: serializing results: 1.760960ms
+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.032995ms
-STATS: parsing XPath query: 0.140905ms
-STATS: compiling XPath query: 1.163960ms
+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: 20.728827ms
-STATS: serializing results: 1.471996ms
+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.924992ms
-STATS: parsing XPath query: 0.141859ms
-STATS: compiling XPath query: 1.188993ms
+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: 22.500992ms
-STATS: serializing results: 1.472950ms
+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.951933ms
-STATS: parsing XPath query: 0.066042ms
-STATS: compiling XPath query: 0.647783ms
+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: 17.152071ms
-STATS: serializing results: 1.544952ms
+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.987934ms
+STATS: parsing xml document: 1.981020ms
 STATS: parsing XPath query: 0.072002ms
-STATS: compiling XPath query: 0.830173ms
+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: 20.501852ms
-STATS: serializing results: 1.707077ms
+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.982927ms
-STATS: parsing XPath query: 0.090122ms
-STATS: compiling XPath query: 0.648975ms
+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.914129ms
-STATS: serializing results: 1.840115ms
+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
 -------------------------------------------
Tree Automata TOOlkit