Skip to content

Commit 6a870f6

Browse files
author
Roy Lin
committed
fix(box): log processor tails console.log instead of stopping at first EOF
run_json_file_processor (and the syslog processor) used `for line in reader.lines()`, whose iterator ENDS at EOF. The `Err(_) => sleep` arm only catches I/O errors, never EOF — so the processor read console.log once, hit EOF, and exited, silently DROPPING every line a container logged after the initial quiet period (the `// EOF — poll for more data` comment shows tailing was intended but not implemented). Replace with a shared `tail_next_line` helper that polls on Ok(0) (true EOF) like `tail -f` and accumulates partial lines (no trailing newline yet) across reads so they aren't split into two records. Applied to the json-file and both syslog (udp/tcp) processors. Unit-tested for complete-line extraction + CRLF trim. NOTE: this fixes the processor LOOP. A separate, deeper bug remains: for detached `run -d`, the processor is a spawn_blocking task in the ephemeral CLI process and dies when it detaches, so container.json is still truncated until the processor is moved to a box-lifetime process (shim/monitor). console.log itself is always complete. Tracked for a follow-up.
1 parent c805e00 commit 6a870f6

1 file changed

Lines changed: 52 additions & 27 deletions

File tree

src/runtime/src/log.rs

Lines changed: 52 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,35 @@ fn is_runtime_console_noise(line: &str) -> bool {
4848
line.starts_with("init.krun:")
4949
}
5050

51+
/// Read the next COMPLETE line from a tailed `console.log`, blocking (with
52+
/// polling) until one is available, and return it WITHOUT the trailing newline.
53+
///
54+
/// This is `tail -f` semantics, which the log processors require: `BufRead`
55+
/// signals EOF with `Ok(0)` (NOT an error), so a plain `reader.lines()` loop
56+
/// ENDS at the first EOF and silently drops every line a container logs after an
57+
/// initial quiet period. Here EOF just means "wait for the file to grow". `buf`
58+
/// accumulates a partial line (no trailing newline yet) across reads so it is
59+
/// completed on the next append instead of being split into two records.
60+
fn tail_next_line(reader: &mut impl BufRead, buf: &mut String) -> String {
61+
loop {
62+
match reader.read_line(buf) {
63+
Ok(0) | Err(_) => {
64+
std::thread::sleep(std::time::Duration::from_millis(200));
65+
continue;
66+
}
67+
Ok(_) => {}
68+
}
69+
if !buf.ends_with('\n') {
70+
// Partial line at EOF — keep it buffered and wait for the rest.
71+
continue;
72+
}
73+
let line = std::mem::take(buf);
74+
return line
75+
.trim_end_matches(|c| c == '\n' || c == '\r')
76+
.to_string();
77+
}
78+
}
79+
5180
/// Tail console.log and write Docker-compatible JSON lines to container.json.
5281
fn run_json_file_processor(console_log: &Path, log_dir: &Path, max_size: u64, max_file: u32) {
5382
// Wait for console.log to appear
@@ -63,22 +92,17 @@ fn run_json_file_processor(console_log: &Path, log_dir: &Path, max_size: u64, ma
6392
Err(_) => return,
6493
};
6594

66-
let reader = BufReader::new(file);
95+
let mut reader = BufReader::new(file);
6796
let json_path = json_log_path(log_dir);
6897
let mut writer = match RotatingWriter::new(&json_path, max_size, max_file) {
6998
Ok(w) => w,
7099
Err(_) => return,
71100
};
72101

73-
for line in reader.lines() {
74-
let line = match line {
75-
Ok(l) => l,
76-
Err(_) => {
77-
// EOF — poll for more data
78-
std::thread::sleep(std::time::Duration::from_millis(200));
79-
continue;
80-
}
81-
};
102+
// Tail console.log (see tail_next_line) and emit one JSON record per line.
103+
let mut buf = String::new();
104+
loop {
105+
let line = tail_next_line(&mut reader, &mut buf);
82106

83107
// Drop libkrun's C-init boot preamble (`init.krun: ...`) printed to the
84108
// console before /sbin/init starts. It is runtime internals, not
@@ -129,22 +153,17 @@ fn run_syslog_processor(console_log: &Path, address: &str, _facility: &str, tag:
129153
("udp", address)
130154
};
131155

132-
let reader = BufReader::new(file);
156+
let mut reader = BufReader::new(file);
157+
let mut buf = String::new();
133158

134159
match proto {
135160
"udp" => {
136161
let socket = match UdpSocket::bind("0.0.0.0:0") {
137162
Ok(s) => s,
138163
Err(_) => return,
139164
};
140-
for line in reader.lines() {
141-
let line = match line {
142-
Ok(l) => l,
143-
Err(_) => {
144-
std::thread::sleep(std::time::Duration::from_millis(200));
145-
continue;
146-
}
147-
};
165+
loop {
166+
let line = tail_next_line(&mut reader, &mut buf);
148167
if is_runtime_console_noise(&line) {
149168
continue;
150169
}
@@ -160,14 +179,8 @@ fn run_syslog_processor(console_log: &Path, address: &str, _facility: &str, tag:
160179
Ok(s) => s,
161180
Err(_) => return,
162181
};
163-
for line in reader.lines() {
164-
let line = match line {
165-
Ok(l) => l,
166-
Err(_) => {
167-
std::thread::sleep(std::time::Duration::from_millis(200));
168-
continue;
169-
}
170-
};
182+
loop {
183+
let line = tail_next_line(&mut reader, &mut buf);
171184
if is_runtime_console_noise(&line) {
172185
continue;
173186
}
@@ -288,6 +301,18 @@ mod tests {
288301
use std::io::Read;
289302
use tempfile::TempDir;
290303

304+
#[test]
305+
fn test_tail_next_line_returns_complete_lines() {
306+
use std::io::Cursor;
307+
// Two complete lines (one CRLF, one LF) are returned newline-stripped.
308+
// A third call would block polling for EOF growth (tail -f), so we stop.
309+
let mut reader = BufReader::new(Cursor::new(b"alpha\r\nbeta\n".to_vec()));
310+
let mut buf = String::new();
311+
assert_eq!(tail_next_line(&mut reader, &mut buf), "alpha");
312+
assert_eq!(tail_next_line(&mut reader, &mut buf), "beta");
313+
assert!(buf.is_empty(), "buffer must be drained after a complete line");
314+
}
315+
291316
#[test]
292317
fn test_is_runtime_console_noise() {
293318
assert!(is_runtime_console_noise("init.krun: mount_filesystems ok"));

0 commit comments

Comments
 (0)