Skip to content

Commit 9e8bbdc

Browse files
committed
Stop the sorted-page cost guard measuring a cache, and give it a clock-free twin
`Build with Java 17 in MacOS` failed on this guard in 5 of the last 12 runs, and only ever on macOS. Two causes, both in the test. **It was warmed into meaninglessness.** `timeOf` ran the query once to warm and then timed three more. But re-querying a collection that was just written measures a cache, not a decode: over these same 2000 fat rows a blocking sort costs 353 ms, then 83 ms, then 0.8 ms. By the timed runs, the decode this guard exists to detect had already been cached away, and what was left was one to five milliseconds of JIT and scheduling — which reads 0.6x on an idle laptop and 4.9x on a loaded runner. Each half is now measured once on a collection no query has touched, and sampled over several fresh ones with the quickest kept, because contention can only ever add time. **It compared a fat collection against a lean one**, assuming the index walk cancelled between them. It does not: the fat collection's index lives in a file two orders of magnitude larger, so walking it costs more I/O for reasons that have nothing to do with decoding. Measured cold, a fat sorted page cost 4.6x a lean one *with the optimisation present and working* — a floor sitting above the 3x threshold, which is the failure CI kept reporting. Both halves are now the same collection shape sorted two ways, indexed against unindexed, so row count, document size, file and returned row all cancel and only the discarded-row decode is left. Measured 4.5x on the worst run of a laptop under load and 45x on the best, against a 2x threshold; a regression does not narrow that ratio, it removes it, because the two halves become one code path. **And a second test with no clock in it at all.** A cost guard's failure mode is not going red, it is going green while measuring nothing, and on a shared runner a timing threshold can only ever be a compromise. `testSortedPageIsPlannedFromTheIndex` asserts the planner sets `sortIndexDescriptor` for a limited sort on an indexed field and leaves it unset for an unindexed one. That cannot be made to flake. Both were confirmed to fail on a planted regression rather than pass vacuously, and they catch different ones: disabling the execution path fails the cost guard and not the plan test, disabling the planner fails the plan test. Test-only; no library code is touched. mvstore module green at 5386 tests.
1 parent 58b9ee5 commit 9e8bbdc

1 file changed

Lines changed: 114 additions & 40 deletions

File tree

‎nitrite-mvstore-adapter/src/test/java/org/dizitart/no2/integration/collection/CollectionSortedFindCostTest.java‎

Lines changed: 114 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,8 @@
1818
package org.dizitart.no2.integration.collection;
1919

2020
import org.dizitart.no2.Nitrite;
21+
import org.dizitart.no2.collection.DocumentCursor;
22+
import org.dizitart.no2.collection.FindPlan;
2123
import org.dizitart.no2.collection.Document;
2224
import org.dizitart.no2.collection.FindOptions;
2325
import org.dizitart.no2.collection.NitriteCollection;
@@ -35,6 +37,8 @@
3537
import static org.dizitart.no2.filters.Filter.ALL;
3638
import static org.dizitart.no2.integration.TestUtil.deleteDb;
3739
import static org.dizitart.no2.integration.TestUtil.getRandomTempDbFile;
40+
import static org.junit.Assert.assertNotNull;
41+
import static org.junit.Assert.assertNull;
3842
import static org.junit.Assert.assertTrue;
3943

4044
/**
@@ -46,15 +50,33 @@
4650
* gap grows with document size, not just document count. Taking the sort keys from the index
4751
* removes the decode: over 2000 rows carrying a 150-element array the sorted page went from
4852
* ~115 ms to ~2 ms.
53+
* <p>
54+
* <b>Both halves of every comparison here are the same collection shape sorted two different
55+
* ways</b>, never a fat collection against a lean one. That earlier framing assumed the index
56+
* walk cancelled between the halves, and it does not: the fat collection's index lives in a
57+
* file two orders of magnitude larger, so walking it costs more I/O for reasons that have
58+
* nothing to do with decoding. Measured cold on macOS, a fat sorted page cost 4.6x a lean one
59+
* <i>with the optimisation present and working</i> - through a 3x threshold, which is why this
60+
* guard failed on that runner and nowhere else.
4961
*
5062
* @author Anindya Chatterjee
5163
*/
5264
public class CollectionSortedFindCostTest {
5365
private static final int ROWS = 2000;
5466
private static final int PAYLOAD = 150;
5567

68+
/**
69+
* Fresh collections per sample, because the cost under test is only visible on a cold one.
70+
* Re-querying a collection that was just written measures a cache: over these same 2000 fat
71+
* rows a blocking sort cost 353 ms, then 83 ms, then 0.8 ms. The old guard warmed once and
72+
* timed the three runs after it, so it was comparing two numbers from which the decode -
73+
* the whole subject of the test - had already been cached away.
74+
*/
75+
private static final int SAMPLES = 3;
76+
5677
private final String fileName = getRandomTempDbFile();
5778
private Nitrite db;
79+
private int collectionSeq;
5880

5981
@Before
6082
public void setUp() {
@@ -72,61 +94,113 @@ public void tearDown() {
7294
}
7395

7496
/**
75-
* The same query, the same row count, the same index - only the size of the documents
76-
* differs. A sorted page that decodes every row pays for the payload of every row, so the
77-
* fat collection costs many times the lean one. A sorted page that decodes only the row it
78-
* returns costs about the same either way.
97+
* The regression detector, and it has no clock in it.
98+
* <p>
99+
* A sorted page that can be answered from an index says so in its {@link FindPlan}: the
100+
* planner sets {@code sortIndexDescriptor} when the query has no filter, one sort field, a
101+
* limit, and a simple index on exactly that field. When it is set the page reads its order
102+
* from the index and fetches only the rows it returns; when it is not, the blocking sort
103+
* decodes every stored document. Asserting on the plan tests that decision directly, and
104+
* cannot be made to flake by a loaded machine - which the cost guard below can.
105+
*/
106+
@Test
107+
public void testSortedPageIsPlannedFromTheIndex() {
108+
NitriteCollection collection = fatCollection("planned");
109+
110+
DocumentCursor fromIndex = collection.find(ALL,
111+
FindOptions.orderBy("seq", SortOrder.Descending).limit(1));
112+
assertNotNull("a limited sort on an indexed field was not planned from the index, so it "
113+
+ "is decoding every stored document to order rows it discards",
114+
fromIndex.getFindPlan().getSortIndexDescriptor());
115+
116+
// The control: the same query shape on a field with no index cannot use that path, so a
117+
// non-null descriptor above would prove nothing on its own.
118+
DocumentCursor blocking = collection.find(ALL,
119+
FindOptions.orderBy("unindexed", SortOrder.Descending).limit(1));
120+
assertNull("a sort on an unindexed field claims an index to read its order from",
121+
blocking.getFindPlan().getSortIndexDescriptor());
122+
}
123+
124+
/**
125+
* The same query, over the same rows, ordered by an indexed field and by an unindexed one.
126+
* Only the second can be answered from an index; the first is what this optimisation
127+
* exists to make cheap. Everything else - row count, document size, the file, the single
128+
* row returned - is identical between the halves, so what is left is the decode of the
129+
* {@link #ROWS} rows neither query should have returned.
79130
* <p>
80-
* Both halves walk an index of identical size and shape, so that cost cancels; what does
81-
* not cancel is the payload of the rows each one decodes. The page is deliberately one row
82-
* rather than twenty: returning a fat document legitimately costs more than returning a
83-
* lean one, and that difference is the floor of this ratio, so the fewer rows the page
84-
* returns the more of the ratio is the {@link #ROWS} rows it should never have touched.
131+
* <b>Cold, and the best of {@link #SAMPLES}.</b> Each half is measured once on a collection
132+
* no query has touched, because a second look at the same collection measures a cache
133+
* rather than a decode. That makes any single sample noisy, so each half is sampled on
134+
* several fresh collections and the quickest is kept: contention can only ever add time, so
135+
* the quickest run is the one least contaminated by the machine.
85136
* <p>
86-
* Deliberately not "sorted page vs. unsorted page", whose halves do not share the index
87-
* walk, nor "sorted page vs. full drain", whose halves share nothing at all. Both halves
88-
* here are measured back to back, under whatever load the machine is under.
137+
* The threshold is 2x against a measured 4.5x on the worst run of a laptop under load and
138+
* 45x on the best. A regression does not narrow this ratio - it removes it, because the two
139+
* halves become the same code path and the ratio becomes 1.
89140
*/
90141
@Test
91-
public void testSortedPageCostDoesNotFollowDocumentSize() {
92-
double lean = sortedPageCost("lean", 0);
93-
double fat = sortedPageCost("fat", PAYLOAD);
142+
public void testSortedPageDoesNotDecodeTheRowsItDiscards() {
143+
warmTheQueryPath();
144+
145+
double indexed = Double.MAX_VALUE;
146+
double blocking = Double.MAX_VALUE;
147+
for (int sample = 0; sample < SAMPLES; sample++) {
148+
// Alternated so that any drift over the run lands on both halves alike.
149+
blocking = Math.min(blocking, coldSortedPageCost("unindexed"));
150+
indexed = Math.min(indexed, coldSortedPageCost("seq"));
151+
}
94152

95-
assertTrue("a sorted page over fat documents took " + fat + "ms against " + lean
96-
+ "ms over lean ones, same row count - it is still decoding rows it discards",
97-
fat < lean * 3);
153+
assertTrue("a sorted page over an indexed field took " + indexed + "ms against "
154+
+ blocking + "ms over an unindexed one, same rows and same documents - it is "
155+
+ "still decoding the rows it discards", blocking > indexed * 2);
98156
}
99157

100-
private double sortedPageCost(String name, int payloadSize) {
101-
NitriteCollection collection = db.getCollection(name);
158+
/**
159+
* JIT only. Run on its own collection so the measured ones stay cache-cold.
160+
*/
161+
private void warmTheQueryPath() {
162+
NitriteCollection collection = fatCollection("warm");
163+
for (int i = 0; i < 3; i++) {
164+
drain(collection, "seq");
165+
drain(collection, "unindexed");
166+
}
167+
}
168+
169+
private double coldSortedPageCost(String sortField) {
170+
NitriteCollection collection = fatCollection("cost");
171+
long start = System.nanoTime();
172+
drain(collection, sortField);
173+
return (System.nanoTime() - start) / 1e6;
174+
}
175+
176+
private static void drain(NitriteCollection collection, String sortField) {
177+
FindOptions page = FindOptions.orderBy(sortField, SortOrder.Descending).limit(1);
178+
for (Document ignored : collection.find(ALL, page)) {
179+
// force the fetch
180+
}
181+
}
182+
183+
/**
184+
* {@link #ROWS} rows carrying a {@link #PAYLOAD}-element array, except the one the page
185+
* returns. Descending on either sort field returns an end of the range, and giving that row
186+
* a payload would put the cost of decoding it into a measurement that is supposed to
187+
* contain only rows that were never returned.
188+
*/
189+
private NitriteCollection fatCollection(String prefix) {
190+
NitriteCollection collection = db.getCollection(prefix + "-" + collectionSeq++);
102191
collection.createIndex(IndexOptions.indexOptions(IndexType.NON_UNIQUE), "seq");
103192

104193
for (int i = 0; i < ROWS; i++) {
105-
Document document = Document.createDocument("seq", i);
106-
if (payloadSize > 0) {
107-
List<Document> payload = new ArrayList<>(payloadSize);
108-
for (int w = 0; w < payloadSize; w++) {
194+
Document document = Document.createDocument("seq", i).put("unindexed", ROWS - i);
195+
if (i != 0 && i != ROWS - 1) {
196+
List<Document> payload = new ArrayList<>(PAYLOAD);
197+
for (int w = 0; w < PAYLOAD; w++) {
109198
payload.add(Document.createDocument("text", "word" + w).put("start", w * 300));
110199
}
111200
document.put("payload", payload);
112201
}
113202
collection.insert(document);
114203
}
115-
116-
FindOptions page = FindOptions.orderBy("seq", SortOrder.Descending).limit(1);
117-
return timeOf(() -> {
118-
for (Document ignored : collection.find(ALL, page)) {
119-
// force the fetch
120-
}
121-
});
122-
}
123-
124-
private static double timeOf(Runnable task) {
125-
task.run(); // warm
126-
long start = System.nanoTime();
127-
for (int i = 0; i < 3; i++) {
128-
task.run();
129-
}
130-
return (System.nanoTime() - start) / 3e6;
204+
return collection;
131205
}
132206
}

0 commit comments

Comments
 (0)