| 38 |
38 |
|
/// millisecond. Short enough to be invisible against the shell's tick.
|
| 39 |
39 |
|
const DRAIN_SLICE: Duration = Duration::from_millis(50);
|
| 40 |
40 |
|
|
|
41 |
+ |
/// How many lines a resolver's command may produce for it to read.
|
|
42 |
+ |
///
|
|
43 |
+ |
/// The commands that resolve are short introspection ones: `lsblk -J`,
|
|
44 |
+ |
/// `findmnt`, `cat /etc/shells`, `cat /etc/passwd`, `ostree admin
|
|
45 |
+ |
/// --print-current-dir`. The largest of those on a fresh install is tens of
|
|
46 |
+ |
/// lines, so this is about a hundred times the real figure and no genuine
|
|
47 |
+ |
/// capture can reach it.
|
|
48 |
+ |
///
|
|
49 |
+ |
/// It exists because "the resolving commands are small" was a fact about the
|
|
50 |
+ |
/// callers holding an unbounded buffer up, and the installer runs on a live
|
|
51 |
+ |
/// medium where `/var` is RAM. Passing it is treated as a failure rather than
|
|
52 |
+ |
/// truncated: a resolver parses structured output, and half a JSON document is
|
|
53 |
+ |
/// how the bug in `4bffd6f` presented, as `EOF while parsing a value` after the
|
|
54 |
+ |
/// disk had already been wiped.
|
|
55 |
+ |
const CAPTURE_LIMIT: usize = 5_000;
|
|
56 |
+ |
|
| 41 |
57 |
|
/// How long the sequence keeps waiting after a reaped command has gone quiet.
|
| 42 |
58 |
|
///
|
| 43 |
59 |
|
/// Measured from the last line rather than from the exit, so a command that is
|
| 112 |
128 |
|
/// the long, chatty commands are all `Run`, and the ones that resolve are
|
| 113 |
129 |
|
/// short introspection commands whose output is measured in kilobytes.
|
| 114 |
130 |
|
captured: Vec<String>,
|
|
131 |
+ |
/// The capture hit [`CAPTURE_LIMIT`], so it is a prefix rather than the
|
|
132 |
+ |
/// output, and no resolver may be handed it.
|
|
133 |
+ |
overflowed: bool,
|
| 115 |
134 |
|
/// What to do with this command's output, for a [`Stage::Resolve`].
|
| 116 |
135 |
|
then: Option<Resolver>,
|
| 117 |
136 |
|
/// Lines from stdout and stderr, interleaved in arrival order.
|
| 175 |
194 |
|
/// the display buffer either way.
|
| 176 |
195 |
|
fn take(&mut self, line: String, into: &mut Vec<String>) {
|
| 177 |
196 |
|
if self.then.is_some() {
|
| 178 |
|
- |
self.captured.push(line.clone());
|
|
197 |
+ |
if self.captured.len() >= CAPTURE_LIMIT {
|
|
198 |
+ |
self.overflowed = true;
|
|
199 |
+ |
} else {
|
|
200 |
+ |
self.captured.push(line.clone());
|
|
201 |
+ |
}
|
| 179 |
202 |
|
}
|
| 180 |
203 |
|
push_line(into, line);
|
| 181 |
204 |
|
}
|
| 182 |
205 |
|
|
| 183 |
|
- |
/// This command's own output, as a resolver wants it.
|
| 184 |
|
- |
fn captured(&self) -> String {
|
| 185 |
|
- |
self.captured.join("\n")
|
|
206 |
+ |
/// This command's own output, as a resolver wants it, or `Err` if there was
|
|
207 |
+ |
/// more of it than [`CAPTURE_LIMIT`] allows.
|
|
208 |
+ |
fn captured(&self) -> Result<String, String> {
|
|
209 |
+ |
if self.overflowed {
|
|
210 |
+ |
return Err(format!(
|
|
211 |
+ |
"the command produced more than {CAPTURE_LIMIT} lines to interpret"
|
|
212 |
+ |
));
|
|
213 |
+ |
}
|
|
214 |
+ |
Ok(self.captured.join("\n"))
|
| 186 |
215 |
|
}
|
| 187 |
216 |
|
|
| 188 |
217 |
|
/// Drain for up to `slice`, stopping early once every line has arrived.
|
| 300 |
329 |
|
self.outcome.is_some()
|
| 301 |
330 |
|
}
|
| 302 |
331 |
|
|
| 303 |
|
- |
/// How many commands are behind and in total, for a progress line.
|
| 304 |
|
- |
pub fn progress(&self) -> (usize, usize) {
|
| 305 |
|
- |
let left = self.queue.len() + usize::from(self.current.is_some());
|
| 306 |
|
- |
let total = self.total();
|
| 307 |
|
- |
(total - left, total)
|
| 308 |
|
- |
}
|
| 309 |
|
- |
|
| 310 |
|
- |
fn total(&self) -> usize {
|
| 311 |
|
- |
// Reconstructed rather than stored, so the two cannot disagree after a
|
| 312 |
|
- |
// failure clears the queue.
|
| 313 |
|
- |
self.queue.len() + usize::from(self.current.is_some()) + self.done_count
|
|
332 |
+ |
/// How many commands have finished, for a progress line.
|
|
333 |
+ |
///
|
|
334 |
+ |
/// A count, not a fraction. The sequence has no total to report: a
|
|
335 |
+ |
/// [`Resolve`](Stage::Resolve) pushes the stages it decides onto the queue
|
|
336 |
+ |
/// while the run is under way, so what starts as four commands ends as
|
|
337 |
+ |
/// nineteen. Returning a denominator that grows meant the run screen showed
|
|
338 |
+ |
/// "Step 1 of 4" and then counted past its own total, which reads as the
|
|
339 |
+ |
/// installer losing track of what it is doing at the exact moment the user
|
|
340 |
+ |
/// is watching a disk being written.
|
|
341 |
+ |
///
|
|
342 |
+ |
/// Declaring the count up front would be the alternative, and it would put
|
|
343 |
+ |
/// the number in one place and the stages that have to match it in another.
|
|
344 |
+ |
/// That is the coupling this file has already been bitten by twice.
|
|
345 |
+ |
pub fn completed(&self) -> usize {
|
|
346 |
+ |
self.done_count
|
| 314 |
347 |
|
}
|
| 315 |
348 |
|
|
| 316 |
349 |
|
/// Advance the sequence: drain output, reap a finished child, start the
|
| 373 |
406 |
|
}
|
| 374 |
407 |
|
|
| 375 |
408 |
|
if let Some(resolve) = finished.then.take() {
|
| 376 |
|
- |
let captured = finished.captured();
|
|
409 |
+ |
let captured = match finished.captured() {
|
|
410 |
+ |
Ok(captured) => captured,
|
|
411 |
+ |
Err(message) => {
|
|
412 |
+ |
self.fail(message);
|
|
413 |
+ |
return;
|
|
414 |
+ |
}
|
|
415 |
+ |
};
|
| 377 |
416 |
|
match resolve(&captured) {
|
| 378 |
417 |
|
// Pushed to the front: what a discovery decides runs before
|
| 379 |
418 |
|
// whatever was queued behind it.
|
| 441 |
480 |
|
Ok(Running {
|
| 442 |
481 |
|
child,
|
| 443 |
482 |
|
captured: Vec::new(),
|
|
483 |
+ |
overflowed: false,
|
| 444 |
484 |
|
then: None,
|
| 445 |
485 |
|
lines: receiver,
|
| 446 |
486 |
|
exited: None,
|
| 783 |
823 |
|
assert!(sequence.outcome().expect("stopped").is_err());
|
| 784 |
824 |
|
}
|
| 785 |
825 |
|
|
|
826 |
+ |
// A capture past the limit is a prefix, and a resolver handed a prefix
|
|
827 |
+ |
// parses half a document. That is how the bug in 4bffd6f presented: "EOF
|
|
828 |
+ |
// while parsing a value" from a disk that had already been wiped and
|
|
829 |
+ |
// deployed. So the sequence fails with a reason instead, which is the one
|
|
830 |
+ |
// outcome the run screen can state plainly.
|
|
831 |
+ |
#[test]
|
|
832 |
+ |
fn a_capture_past_the_limit_fails_rather_than_resolving_a_prefix() {
|
|
833 |
+ |
let mut log = CommandLog::new();
|
|
834 |
+ |
let noisy = format!("seq {}", CAPTURE_LIMIT + 100);
|
|
835 |
+ |
let mut sequence = Sequence::new(vec![Stage::Resolve {
|
|
836 |
+ |
invocation: Invocation::new("sh").args(["-c", &noisy]),
|
|
837 |
+ |
then: Box::new(|_| panic!("a resolver was handed a truncated capture")),
|
|
838 |
+ |
}]);
|
|
839 |
+ |
|
|
840 |
+ |
drive(&mut sequence, &mut log);
|
|
841 |
+ |
|
|
842 |
+ |
let Some(Err(message)) = sequence.outcome() else {
|
|
843 |
+ |
panic!("the sequence did not fail");
|
|
844 |
+ |
};
|
|
845 |
+ |
assert!(message.contains(&CAPTURE_LIMIT.to_string()), "{message}");
|
|
846 |
+ |
}
|
|
847 |
+ |
|
|
848 |
+ |
// The display buffer still wraps at its own bound while a capture is being
|
|
849 |
+ |
// held whole, which is the guarantee 4bffd6f established.
|
|
850 |
+ |
#[test]
|
|
851 |
+ |
fn a_capture_under_the_limit_is_kept_whole() {
|
|
852 |
+ |
let mut log = CommandLog::new();
|
|
853 |
+ |
let noisy = format!("seq {}", SCROLLBACK * 2);
|
|
854 |
+ |
let mut sequence = Sequence::new(vec![Stage::Resolve {
|
|
855 |
+ |
invocation: Invocation::new("sh").args(["-c", &noisy]),
|
|
856 |
+ |
then: Box::new(|captured| {
|
|
857 |
+ |
assert_eq!(
|
|
858 |
+ |
captured.lines().count(),
|
|
859 |
+ |
SCROLLBACK * 2,
|
|
860 |
+ |
"the capture was trimmed under the limit"
|
|
861 |
+ |
);
|
|
862 |
+ |
Ok(Vec::new())
|
|
863 |
+ |
}),
|
|
864 |
+ |
}]);
|
|
865 |
+ |
|
|
866 |
+ |
drive(&mut sequence, &mut log);
|
|
867 |
+ |
|
|
868 |
+ |
assert_eq!(sequence.outcome(), Some(&Ok(())));
|
|
869 |
+ |
}
|
|
870 |
+ |
|
| 786 |
871 |
|
// The bound is the buffer's, not the caller's. An equality test enforces
|
| 787 |
872 |
|
// it only while every append comes through push_line, which is a fact
|
| 788 |
873 |
|
// about today's callers rather than about the buffer, and one append
|
| 805 |
890 |
|
Stage::Run(Invocation::new("true")),
|
| 806 |
891 |
|
Stage::Run(Invocation::new("true")),
|
| 807 |
892 |
|
]);
|
| 808 |
|
- |
assert_eq!(sequence.progress(), (0, 3));
|
|
893 |
+ |
assert_eq!(sequence.completed(), 0);
|
| 809 |
894 |
|
|
| 810 |
895 |
|
drive(&mut sequence, &mut log);
|
| 811 |
896 |
|
|
| 812 |
|
- |
assert_eq!(sequence.progress(), (3, 3));
|
|
897 |
+ |
assert_eq!(sequence.completed(), 3);
|
| 813 |
898 |
|
}
|
| 814 |
899 |
|
|
| 815 |
900 |
|
// Nothing starts during construction, so the run screen is on screen before
|
| 829 |
914 |
|
sequence.poll(&mut log);
|
| 830 |
915 |
|
|
| 831 |
916 |
|
assert_eq!(sequence.outcome(), Some(&Ok(())));
|
| 832 |
|
- |
assert_eq!(sequence.progress(), (0, 0));
|
|
917 |
+ |
assert_eq!(sequence.completed(), 0);
|
| 833 |
918 |
|
}
|
| 834 |
919 |
|
}
|