Oregami
Repositories/oxedyne/ore

oxedyne/ore/cli/tests/listing.rs

17.2 KiB, 26 runs

created by r2848102244:1083, which is this file's identity for as long as the history lasts, whatever it is later renamed to

download · who wrote it · its history

1//! What the history listing must never do, which is answer for a store it was
2//! not taken from.
3//!
4//! `ore log` is answered from `.ore/listing` where that listing still describes
5//! the store and the working copy has not moved. Every one of these tests puts
6//! the repository into a state where it does not, and asserts two things: the
7//! answer is the answer the whole log gives, and the command said out loud that
8//! it read the whole log. The second matters as much as the first. The same
9//! feature shipped inert on the server side of this and nothing said so; a cache
10//! that falls back in silence is a cache nobody can tell is not working.
11//!
12//! The differential is the load-bearing one: the same repository asked twice,
13//! once with the listing thrown away and once with it there, must print the same
14//! bytes.
15
16mod support;
17
18use support::{
19 ore,
20 write,
21 Ran,
22 Scratch,
23};
24
25use oxedyne_fe2o3_core::prelude::*;
26
27use std::fs;
28use std::path::{
29 Path,
30 PathBuf,
31};
32use std::time::{
33 Duration,
34 SystemTime,
35};
36
37
38/// The sentence the tool prints when it did not use the listing.
39const SAID: &str = "the history listing was not used";
40
41
42/// Puts a file's modification time back, so that a test wanting the working copy
43/// index believed can get past the window in which a time means nothing.
44fn backdate(path: &Path, secs: u64)
45 -> Outcome<()>
46{
47 let when = match SystemTime::now().checked_sub(Duration::from_secs(secs)) {
48 Some(t) => t,
49 None => return Err(err!("The clock is before the epoch."; Test)),
50 };
51 let file = res!(fs::OpenOptions::new().write(true).open(path));
52 res!(file.set_modified(when));
53 Ok(())
54}
55
56/// A repository with some history and a listing that describes it.
57///
58/// Two named marks with work between them, so that the listing has spans to
59/// count rather than only a header to print.
60fn settled(what: &str)
61 -> Outcome<(Scratch, PathBuf)>
62{
63 let scratch = res!(Scratch::new(what));
64 let root = res!(scratch.sub("work"));
65 res!(res!(ore(&root, &["init"])).good("init"));
66 res!(write(&root, "a.txt", b"one two three four five six seven\n"));
67 res!(res!(ore(&root, &["mark", "first"])).good("mark"));
68 res!(write(&root, "b.txt", b"eight nine ten\n"));
69 res!(write(&root, "a.txt", b"one two three FOUR five six seven\n"));
70 res!(res!(ore(&root, &["mark", "second"])).good("mark"));
71 res!(write(&root, "c.txt", b"eleven\n"));
72 res!(res!(ore(&root, &["log"])).good("log"));
73 for name in ["a.txt", "b.txt", "c.txt"] {
74 res!(backdate(&root.join(name), 60));
75 }
76 // One that appends nothing, which is the one that leaves an index and a
77 // listing.
78 res!(res!(ore(&root, &["log"])).good("log"));
79 let path = listing_path(&root);
80 if !path.is_file() {
81 return Err(err!("No listing was written at {:?}.", path; Test, Missing));
82 }
83 Ok((scratch, root))
84}
85
86fn listing_path(root: &Path) -> PathBuf {
87 root.join(".ore").join("listing")
88}
89
90/// Every segment of a store, oldest first.
91fn segments(root: &Path)
92 -> Outcome<Vec<PathBuf>>
93{
94 let mut names: Vec<PathBuf> = res!(fs::read_dir(root.join(".ore").join("log")))
95 .filter_map(|e| e.ok().map(|e| e.path()))
96 .collect();
97 names.sort();
98 Ok(names)
99}
100
101fn oldest_segment(root: &Path)
102 -> Outcome<PathBuf>
103{
104 let all = res!(segments(root));
105 match all.first() {
106 Some(p) => Ok(p.clone()),
107 None => Err(err!("The store has no segments."; Test, Missing)),
108 }
109}
110
111fn newest_segment(root: &Path)
112 -> Outcome<PathBuf>
113{
114 let all = res!(segments(root));
115 match all.last() {
116 Some(p) => Ok(p.clone()),
117 None => Err(err!("The store has no segments."; Test, Missing)),
118 }
119}
120
121/// A repository whose history has passed a segment boundary, so that the oldest
122/// segment is one nothing will ever append to again.
123///
124/// The tests about a finished segment need one, and a small fixture has only the
125/// segment that is still growing -- which is checked by its bytes rather than by
126/// its stamp, and would pass a test about stamps for the wrong reason.
127fn rolled_over(what: &str)
128 -> Outcome<(Scratch, PathBuf)>
129{
130 let (scratch, root) = res!(settled(what));
131 let mut bulk = Vec::with_capacity(1 << 21);
132 for n in 0..(1u32 << 16) {
133 bulk.extend_from_slice(fmt!("line {} of a file large enough to fill a segment\n", n)
134 .as_bytes());
135 }
136 res!(write(&root, "big.txt", &bulk));
137 res!(res!(ore(&root, &["mark", "bulk"])).good("mark"));
138 if res!(segments(&root)).len() < 2 {
139 return Err(err!(
140 "The fixture wrote {} bytes and the store still holds one segment.",
141 bulk.len();
142 Test, Mismatch));
143 }
144 res!(backdate(&root.join("big.txt"), 60));
145 res!(res!(ore(&root, &["log"])).good("log"));
146 Ok((scratch, root))
147}
148
149/// Runs `ore log` and insists it took the listing.
150fn from_listing(root: &Path, args: &[&str])
151 -> Outcome<String>
152{
153 let ran = res!(ore(root, args));
154 let out = fmt!("{}", res!(ran.good("log")));
155 if ran.err.contains(SAID) {
156 return Err(err!(
157 "`ore {:?}` was expected to answer from the listing and read the whole log: \
158 {}", args, ran.err;
159 Test, Mismatch));
160 }
161 Ok(out)
162}
163
164/// Runs `ore log` and insists it did not, and said so.
165fn said_whole(ran: &Ran, why: &str)
166 -> Outcome<String>
167{
168 let out = fmt!("{}", res!(ran.good("log")));
169 if !ran.err.contains(SAID) {
170 return Err(err!(
171 "The whole log was read because {}, and nothing said so. What it said was \
172 {:?}.", why, ran.err;
173 Test, Missing));
174 }
175 Ok(out)
176}
177
178
179/// **The load-bearing test.** The listing answers exactly what the log answers.
180///
181/// Asked twice with nothing changed between: once with the listing removed, so
182/// the whole log is read, and once with the listing the first run left. The two
183/// must be the same bytes, and the two runs must have taken different paths --
184/// which is asserted rather than assumed, because a test where both runs read
185/// the whole log would pass while proving nothing.
186#[test]
187fn the_listing_says_what_the_log_says() -> Outcome<()> {
188 for auto in [false, true] {
189 let args: Vec<&str> = match auto {
190 true => vec!["log", "--auto"],
191 false => vec!["log"],
192 };
193 let (_scratch, root) = res!(settled("differential"));
194 fs::remove_file(listing_path(&root)).ok();
195 let whole = res!(said_whole(&res!(ore(&root, &args)), "the listing was removed"));
196 let kept = res!(from_listing(&root, &args));
197 assert_eq!(whole, kept,
198 "`ore {:?}` from the whole log and from the listing", args);
199 // And it is not empty agreement: the listing this was read from holds the
200 // marks the output names.
201 assert!(whole.contains("\"first\"") && whole.contains("\"second\""),
202 "the fixture must have marks to compare: {}", whole);
203 }
204 Ok(())
205}
206
207/// An operation appended under the listing is seen, and the listing is not used.
208///
209/// This is the case the fleet is in: one working copy, several sessions, each
210/// running verbs in it. A command that appends now carries the listing past what
211/// it wrote, so the stale one is deliberately put back over it here -- because
212/// the guarantee is not that the tool keeps its own listing current, it is that a
213/// listing taken before an append cannot answer for the store after one. A
214/// process killed between the append and the carrying leaves exactly this, and so
215/// does a second session that wrote while this one was reading.
216#[test]
217fn an_append_under_the_listing_is_caught() -> Outcome<()> {
218 let (_scratch, root) = res!(settled("appended"));
219 let before = res!(from_listing(&root, &["log"]));
220 let held = res!(fs::read(listing_path(&root)));
221 res!(res!(ore(&root, &["mark", "third"])).good("mark"));
222 assert!(listing_path(&root).is_file(),
223 "a command that appended carries its listing past what it wrote");
224 assert_ne!(res!(fs::read(listing_path(&root))), held,
225 "and what it leaves is not the listing it began with");
226 res!(fs::write(listing_path(&root), &held));
227 let ran = res!(ore(&root, &["log"]));
228 let after = res!(said_whole(&ran, "an operation was appended"));
229 assert!(ran.err.contains("appended to the segment"),
230 "and the refusal must name what grew: {}", ran.err);
231 assert!(after.contains("\"third\""),
232 "the operation appended after the listing must be in the answer: {}", after);
233 assert!(!before.contains("\"third\""),
234 "and the fixture must not have held it already: {}", before);
235 Ok(())
236}
237
238/// A finished segment that moved under the listing is refused by name.
239///
240/// Nothing appends to a segment that has been finished, so one whose length or
241/// modification time has moved is not the file the listing was taken from. The
242/// modification time alone is moved here, which is the case a length check would
243/// miss.
244#[test]
245fn a_finished_segment_that_moved_is_refused() -> Outcome<()> {
246 let (_scratch, root) = res!(rolled_over("moved_segment"));
247 res!(from_listing(&root, &["log"]));
248 let first = res!(oldest_segment(&root));
249 let was = res!(fs::metadata(&first)).len();
250 let file = res!(fs::OpenOptions::new().write(true).open(&first));
251 res!(file.set_modified(SystemTime::now()));
252 drop(file);
253 assert_eq!(res!(fs::metadata(&first)).len(), was,
254 "the fixture must move the time and not the length");
255 let ran = res!(ore(&root, &["log"]));
256 let out = res!(said_whole(&ran, "a finished segment moved"));
257 assert!(ran.err.contains("Nothing appends to a segment that has been finished"),
258 "and the refusal must name what about it moved: {}", ran.err);
259 assert!(out.contains("\"second\""), "the answer is still the whole answer: {}", out);
260 Ok(())
261}
262
263/// The one segment that may grow is checked by its bytes and not by its stamp.
264///
265/// A byte of it is rewritten in place and both the length and the modification
266/// time are put back, which is the state a length and a timestamp cannot tell
267/// from an untouched file. What catches it is the hash of the bytes the listing
268/// was taken over, which is read again rather than believed.
269#[test]
270fn the_growing_segment_is_checked_by_its_bytes() -> Outcome<()> {
271 let (_scratch, root) = res!(settled("rewritten_tail"));
272 res!(from_listing(&root, &["log"]));
273 let tail = res!(newest_segment(&root));
274 let meta = res!(fs::metadata(&tail));
275 let was_len = meta.len();
276 let was_time = res!(meta.modified());
277 let mut bytes = res!(fs::read(&tail));
278 let at = bytes.len() / 2;
279 bytes[at] ^= 0xff;
280 res!(fs::write(&tail, &bytes));
281 let file = res!(fs::OpenOptions::new().write(true).open(&tail));
282 res!(file.set_modified(was_time));
283 drop(file);
284 let now = res!(fs::metadata(&tail));
285 assert_eq!(now.len(), was_len, "the fixture must keep the length");
286 assert_eq!(res!(now.modified()), was_time, "and the modification time");
287 let ran = res!(ore(&root, &["log"]));
288 assert!(ran.err.contains(SAID),
289 "a rewritten tail must not be answered from the listing: {}{}",
290 ran.out, ran.err);
291 Ok(())
292}
293
294/// A listing this build cannot read is an absent listing, not an error.
295///
296/// Each spoiled listing is the real one with exactly one thing wrong with it, so
297/// that what is tested is the fault and not the absence of everything else. A
298/// listing built from nothing would be refused for want of its other lines and
299/// would say nothing about the line it was meant to be about.
300#[test]
301fn a_listing_that_does_not_parse_is_ignored() -> Outcome<()> {
302 for (what, spoil) in [
303 ("a format line this build does not know",
304 (|lines: &mut Vec<String>| lines[0] = fmt!("ORELIST 99")) as fn(&mut Vec<String>)),
305 ("a count that is not a number", |lines: &mut Vec<String>| {
306 for line in lines.iter_mut() {
307 if line.starts_with("ops ") {
308 *line = fmt!("ops later-on");
309 }
310 }
311 }),
312 ("a line nobody wrote", |lines: &mut Vec<String>| {
313 lines.push(fmt!("something nobody wrote"));
314 }),
315 ("two marks out of the order they stand in", |lines: &mut Vec<String>| {
316 let at: Vec<usize> = lines.iter().enumerate()
317 .filter(|(_, l)| l.starts_with("mark "))
318 .map(|(i, _)| i)
319 .collect();
320 lines.swap(at[0], at[1]);
321 }),
322 ("a mark standing past the end of the log", |lines: &mut Vec<String>| {
323 for line in lines.iter_mut() {
324 if line.starts_with("ops ") {
325 *line = fmt!("ops 1");
326 }
327 }
328 }),
329 ] {
330 let (_scratch, root) = res!(settled("unparseable"));
331 let whole = res!(from_listing(&root, &["log"]));
332 let mut lines: Vec<String> = res!(fs::read_to_string(listing_path(&root)))
333 .lines()
334 .map(|l| fmt!("{}", l))
335 .collect();
336 spoil(&mut lines);
337 res!(fs::write(listing_path(&root), fmt!("{}\n", lines.join("\n")).as_bytes()));
338 let ran = res!(ore(&root, &["log"]));
339 let out = res!(said_whole(&ran, what));
340 assert_eq!(out, whole, "and the answer is the whole answer, for {}", what);
341 }
342 Ok(())
343}
344
345/// A working copy that has moved is captured, and the listing is not used.
346///
347/// The listing says nothing about the working copy and could not notice this on
348/// its own; what notices is the index, asked before the listing is believed.
349#[test]
350fn an_edit_is_captured_rather_than_answered_from_the_listing() -> Outcome<()> {
351 let (_scratch, root) = res!(settled("edited"));
352 res!(from_listing(&root, &["log"]));
353 res!(write(&root, "a.txt", b"one two three four five six seven eight\n"));
354 let ran = res!(ore(&root, &["log"]));
355 let out = res!(said_whole(&ran, "the working copy was edited"));
356 assert!(out.contains("captured"), "the edit must be captured: {}", out);
357 assert!(!out.contains("captured nothing"),
358 "and captured means captured, not reported clean: {}", out);
359 // The command that captured carried its listing past what it appended, so the
360 // next one is answered from it. The edited file is put back beyond the window
361 // in which a modification time means nothing, which is the working copy
362 // index's rule and not this one's.
363 assert!(listing_path(&root).is_file(),
364 "a command that appended carries its listing past what it wrote");
365 // The listing is current and the working copy index is not: the capture
366 // measured the file it had just been handed, inside the window in which a
367 // modification time means nothing. Putting the file back past that window and
368 // asking once settles the index, and the command that does it appends
369 // nothing. Then both are believed.
370 res!(backdate(&root.join("a.txt"), 60));
371 res!(said_whole(&res!(ore(&root, &["log"])), "the index was written too soon"));
372 res!(from_listing(&root, &["log"]));
373 Ok(())
374}
375
376/// **A mark costs the next command nothing.** The listing it leaves is the
377/// listing a whole read would have left, and the next command uses it.
378///
379/// This is the sequence the fleet runs on every commit in every tree on this
380/// machine, since the `post-commit` hook marks: `mark` and then something that
381/// reads. It used to pay one whole read between the two, because an append moved
382/// the store past the cursor the command had read under and everything derived
383/// from that cursor had to be thrown away.
384///
385/// The differential is what makes it worth asserting rather than timing. A
386/// listing carried past an append and a listing taken by reading the whole log
387/// afterwards must be the same bytes: a carried one that was subtly behind would
388/// answer questions about a history that had already moved, and no test that only
389/// watched it be used would notice.
390#[test]
391fn a_mark_carries_the_listing_past_what_it_wrote() -> Outcome<()> {
392 let (_scratch, root) = res!(settled("carried"));
393 res!(res!(ore(&root, &["mark", "third"])).good("mark"));
394 let carried = res!(fs::read_to_string(listing_path(&root)));
395
396 // The answer the carried listing gives, and the command saying it used one.
397 let kept = res!(from_listing(&root, &["log"]));
398 assert!(kept.contains("\"third\""),
399 "the mark just written is in the answer: {}", kept);
400
401 // The same repository read whole, which is the oracle. Nothing has appended
402 // in between, so the listing a whole read leaves is the listing the mark
403 // should have left.
404 res!(fs::remove_file(listing_path(&root)));
405 let whole = res!(said_whole(&res!(ore(&root, &["log"])), "the listing was removed"));
406 assert_eq!(kept, whole, "the carried listing answers what the whole log answers");
407 let taken = res!(fs::read_to_string(listing_path(&root)));
408 assert_eq!(carried, taken,
409 "and it is the same listing, byte for byte, as one taken by reading");
410 Ok(())
411}
412
413/// Asking a question writes nothing, which is what it did before there was a
414/// listing to write.
415///
416/// A verb on a working copy that has not moved says it captured nothing and
417/// leaves the disk alone. It must not quietly start writing a file every time
418/// somebody asks, so the listing is written only where what is on the disk is
419/// not already it.
420///
421/// `ore flags` is the verb asked, because it reads the whole log every time --
422/// its answer is the render and no listing can hold that -- so it reaches the
423/// place a listing is written, twice. `ore log` is asked too, for the other half:
424/// it is answered from the listing, and a path that answered from a file and then
425/// wrote it would be a question that writes.
426#[test]
427fn a_question_asked_twice_writes_nothing_the_second_time() -> Outcome<()> {
428 let (_scratch, root) = res!(settled("no_write"));
429 let path = listing_path(&root);
430 for args in [vec!["flags"], vec!["log"]] {
431 res!(res!(ore(&root, &args)).good("verb"));
432 let was = res!(fs::metadata(&path));
433 let stamp = res!(was.modified());
434 // Far enough apart that a filesystem could tell two writes apart. See the
435 // working copy index for what this window is about.
436 std::thread::sleep(Duration::from_millis(20));
437 res!(res!(ore(&root, &args)).good("verb"));
438 let now = res!(fs::metadata(&path));
439 assert_eq!(res!(now.modified()), stamp,
440 "`ore {:?}` must not rewrite the listing", args);
441 assert_eq!(now.len(), was.len(), "nor replace it with an identical one");
442 }
443 Ok(())
444}