Skip to content

Commit cf22afc

Browse files
authored
[oxlog] sort log files before printing them out (#5356)
Found this while attempting to debug core files during today's mupdate -- I was confused about logs getting skipped for a bit. We should sort log files so they're printed in ascending order, disregarding the directories they're from. Sort by filename only, because log files can go in. Sorting by file name sorts by (service name, timestamp), which is the order we want 99% of the time. There is one wrinkle here, which is that for log files that are written before NTP sync, the timestamps are of the form: ``` /pool/ext/f522118c-5dcd-4116-8044-07f0cceec52e/crypt/debug/oxz_switch/oxide-wicketd:default.log.536112897 ``` But for log files written after NTP sync, they're of the form: ``` /pool/ext/f522118c-5dcd-4116-8044-07f0cceec52e/crypt/debug/oxz_switch/oxide-wicketd:default.log.1699421382 ``` The latter gets sorted before the former, which isn't ideal. But also it works fine and achieves the goal of keeping related logs together. (Note that sorting by file name is possible with `sort` but a bit hard. Something like `sort -t/ -k7` would work: the `7` here indicates the depth at which log files are found.)
1 parent bf5c4b5 commit cf22afc

File tree

1 file changed

+85
-0
lines changed

1 file changed

+85
-0
lines changed

Diff for: dev-tools/oxlog/src/lib.rs

+85
Original file line numberDiff line numberDiff line change
@@ -98,6 +98,10 @@ impl LogFile {
9898
}
9999
}
100100
}
101+
102+
pub fn file_name_cmp(&self, other: &Self) -> std::cmp::Ordering {
103+
self.path.file_name().cmp(&other.path.file_name())
104+
}
101105
}
102106

103107
impl PartialEq for LogFile {
@@ -142,6 +146,22 @@ pub struct SvcLogs {
142146
pub extra: Vec<LogFile>,
143147
}
144148

149+
impl SvcLogs {
150+
/// Sort the archived and extra log files by filename.
151+
///
152+
/// readdir traverses over directories in indeterminate order, so sort by
153+
/// filename (which is enough to sort by service name and timestamp in most
154+
/// cases).
155+
///
156+
/// Generally we don't want to sort by full path, because log files may be
157+
/// scattered across several different directories -- and we care more
158+
/// about filename than which directory they are in.
159+
pub fn sort_by_file_name(&mut self) {
160+
self.archived.sort_unstable_by(LogFile::file_name_cmp);
161+
self.extra.sort_unstable_by(LogFile::file_name_cmp);
162+
}
163+
}
164+
145165
// These probably don't warrant newtypes. They are just to make the
146166
// keys in maps a bit easier to read.
147167
type ZoneName = String;
@@ -284,10 +304,19 @@ impl Zones {
284304
load_extra_logs(dir, svc_name, &mut output, filter.show_empty);
285305
}
286306
}
307+
308+
sort_logs(&mut output);
309+
287310
output
288311
}
289312
}
290313

314+
fn sort_logs(output: &mut BTreeMap<String, SvcLogs>) {
315+
for svc_logs in output.values_mut() {
316+
svc_logs.sort_by_file_name();
317+
}
318+
}
319+
291320
const OX_SMF_PREFIXES: [&str; 2] = ["oxide-", "system-illumos-"];
292321

293322
/// Return true if the provided file name appears to be a valid log file for an
@@ -464,4 +493,60 @@ mod tests {
464493
)
465494
.is_none());
466495
}
496+
497+
#[test]
498+
fn test_sort_logs() {
499+
use super::{LogFile, SvcLogs};
500+
use std::collections::BTreeMap;
501+
502+
let mut logs = BTreeMap::new();
503+
logs.insert(
504+
"blah".to_string(),
505+
SvcLogs {
506+
current: None,
507+
archived: vec![
508+
// "foo" comes after "bar", but the sorted order should
509+
// have 1600000000 before 1700000000.
510+
LogFile {
511+
path: "/bar/blah:default.log.1700000000".into(),
512+
size: None,
513+
modified: None,
514+
},
515+
LogFile {
516+
path: "/foo/blah:default.log.1600000000".into(),
517+
size: None,
518+
modified: None,
519+
},
520+
],
521+
extra: vec![
522+
// "foo" comes after "bar", but the sorted order should
523+
// have log1 before log2.
524+
LogFile {
525+
path: "/foo/blah/sub.default.log1".into(),
526+
size: None,
527+
modified: None,
528+
},
529+
LogFile {
530+
path: "/bar/blah/sub.default.log2".into(),
531+
size: None,
532+
modified: None,
533+
},
534+
],
535+
},
536+
);
537+
538+
super::sort_logs(&mut logs);
539+
540+
let svc_logs = logs.get("blah").unwrap();
541+
assert_eq!(
542+
svc_logs.archived[0].path,
543+
"/foo/blah:default.log.1600000000"
544+
);
545+
assert_eq!(
546+
svc_logs.archived[1].path,
547+
"/bar/blah:default.log.1700000000"
548+
);
549+
assert_eq!(svc_logs.extra[0].path, "/foo/blah/sub.default.log1");
550+
assert_eq!(svc_logs.extra[1].path, "/bar/blah/sub.default.log2");
551+
}
467552
}

0 commit comments

Comments
 (0)