Capture log file mtimes in support bundles #9222
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -451,11 +451,11 @@ impl LogsHandle { | |
| service: &str, | ||
| zip: &mut zip::ZipWriter<W>, | ||
| log_snapshots: &mut LogSnapshots, | ||
| logfile: &LogFile, | ||
| logtype: LogType, | ||
| ) -> Result<(), LogError> { | ||
| let snapshot_logfile = | ||
| self.find_log_in_snapshot(log_snapshots, &logfile.path).await?; | ||
|
|
||
| if logtype == LogType::Current { | ||
| // Since we are processing the current log files in a zone we need | ||
|
|
@@ -501,13 +501,24 @@ impl LogsHandle { | |
| .filter(|f| is_log_file(f.path(), filename)) | ||
| { | ||
| let logfile = f.path(); | ||
| let system_mtime = | ||
| f.metadata().and_then(|m| m.modified()).inspect_err(|e| { | ||
|
There was a problem hiding this comment.
There was a problem hiding this comment. Right, this is fine today. On the one hand I don't foresee us copying over symlinks from a sled zip, but there's no harm in handling them just in case. Switched to |
||
| warn!(&self.log, "sled-diagnostic failed to get mtime of logfile"; | ||
| "error" => %e, | ||
| "logfile" => %logfile, | ||
| ); | ||
| }).ok(); | ||
| let mtime = system_mtime | ||
| .and_then(|m| jiff::Timestamp::try_from(m).ok()); | ||
|
|
||
| if logfile.is_file() { | ||
| write_log_to_zip( | ||
| &self.log, | ||
| service, | ||
| zip, | ||
| LogType::Current, | ||
| logfile, | ||
| mtime, | ||
| )?; | ||
| } | ||
| } | ||
|
|
@@ -522,6 +533,7 @@ impl LogsHandle { | |
| zip, | ||
| logtype, | ||
| &snapshot_logfile, | ||
| logfile.modified, | ||
| )?; | ||
| } | ||
| false => { | ||
|
|
@@ -612,7 +624,7 @@ impl LogsHandle { | |
| &service, | ||
| &mut zip, | ||
| &mut log_snapshots, | ||
| ¤t, | ||
| LogType::Current, | ||
| ) | ||
| .await?; | ||
|
|
@@ -628,13 +640,13 @@ impl LogsHandle { | |
| .archived | ||
| .into_iter() | ||
| .filter(|log| log.path.as_str().contains("crypt/debug")) | ||
| .collect(); | ||
|
|
||
| // Since these logs can be spread out across multiple U.2 devices | ||
| // we need to sort them by timestamp. | ||
| archived.sort_by_key(|log| { | ||
| log.path | ||
| .as_str() | ||
| .rsplit_once(".") | ||
| .and_then(|(_, date)| date.parse::<u64>().ok()) | ||
| .unwrap_or(0) | ||
|
|
@@ -703,6 +715,7 @@ fn write_log_to_zip<W: Write + Seek>( | |
| zip: &mut zip::ZipWriter<W>, | ||
| logtype: LogType, | ||
| snapshot_logfile: &Utf8Path, | ||
| mtime: Option<jiff::Timestamp>, | ||
| ) -> Result<(), LogError> { | ||
| let Some(log_name) = snapshot_logfile.file_name() else { | ||
| warn!( | ||
|
|
@@ -715,10 +728,19 @@ fn write_log_to_zip<W: Write + Seek>( | |
| }; | ||
|
|
||
| let mut src = File::open(&snapshot_logfile)?; | ||
|
|
||
| let zip_mtime = mtime | ||
| .and_then(|ts| { | ||
| let zoned = ts.in_tz("UTC").ok()?; | ||
| zip::DateTime::try_from(zoned.datetime()).ok() | ||
| }) | ||
| .unwrap_or_else(zip::DateTime::default); | ||
|
|
||
| let zip_path = format!("{service}/{logtype}/{log_name}"); | ||
| zip.start_file_from_path( | ||
| zip_path, | ||
| FullFileOptions::default() | ||
| .last_modified_time(zip_mtime) | ||
| .compression_method(zip::CompressionMethod::Zstd) | ||
| .compression_level(Some(3)) | ||
| // NB: From the docs | ||
|
|
@@ -757,8 +779,8 @@ enum ExtraLogKind<'a> { | |
|
|
||
| #[derive(Debug, Default, PartialEq)] | ||
| struct ExtraLogs<'a> { | ||
| current: Option<&'a LogFile>, | ||
| rotated: Vec<&'a LogFile>, | ||
| } | ||
|
|
||
| fn sort_extra_logs<'a>( | ||
|
|
@@ -780,15 +802,15 @@ fn sort_extra_logs<'a>( | |
| warn!( | ||
| logger, | ||
| "found multiple current log files for {name}"; | ||
| "old" => %old_path.path, | ||
| "new" => %log.path, | ||
| ); | ||
| } | ||
| entry.current = Some(&log); | ||
| } | ||
| ExtraLogKind::Rotated { name, log } => { | ||
| let entry = res.entry(name).or_default(); | ||
| entry.rotated.push(&log); | ||
| } | ||
| } | ||
| } | ||
|
|
@@ -838,9 +860,9 @@ fn sort_cockroach_extra_logs(logs: &[LogFile]) -> HashMap<&str, ExtraLogs<'_>> { | |
| let entry = interested.entry(prefix).or_default(); | ||
|
|
||
| if file_name == format!("{prefix}.log") { | ||
| entry.current = Some(log); | ||
| } else { | ||
| entry.rotated.push(log); | ||
| } | ||
| } | ||
| } | ||
|
|
@@ -917,52 +939,30 @@ mod test { | |
| "bogus.log", | ||
| "some/dir" | ||
| ].into_iter().map(|l| { | ||
| oxlog::LogFile { path: Utf8PathBuf::from(l), size: None, modified: None } | ||
| }).collect(); | ||
| let logs_map: HashMap<_, _> = | ||
| logs.iter().map(|l| (l.path.as_str(), l)).collect(); | ||
|
|
||
| let mut expected: HashMap<&str, ExtraLogs<'_>> = HashMap::new(); | ||
|
|
||
| // cockroach | ||
| expected.entry("cockroach").or_default().current = | ||
| Some(&logs_map["cockroach.log"]); | ||
| expected.entry("cockroach").or_default().rotated.push(&logs_map["cockroach.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2025-01-31T17_11_45Z.011435.log"]); | ||
| expected.entry("cockroach").or_default().rotated.push(&logs_map["cockroach.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2025-02-01T01_51_51Z.011486.log"]); | ||
|
|
||
| // cockroach-health | ||
| expected.entry("cockroach-health").or_default().current = | ||
| Some(&logs_map["cockroach-health.log"]); | ||
| expected.entry("cockroach-health").or_default().rotated.push(&logs_map["cockroach-health.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2025-01-31T21_43_26Z.011435.log"]); | ||
| expected.entry("cockroach-health").or_default().rotated.push(&logs_map["cockroach-health.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2025-02-01T01_51_53Z.011486.log"]); | ||
|
|
||
| // cockroach-stderr | ||
| expected.entry("cockroach-stderr").or_default().current = | ||
| Some(&logs_map["cockroach-stderr.log"]); | ||
| expected.entry("cockroach-stderr").or_default().rotated.push(&logs_map["cockroach-stderr.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2023-08-30T18_56_19Z.011950.log"]); | ||
| expected.entry("cockroach-stderr").or_default().rotated.push(&logs_map["cockroach-stderr.oxzcockroachdba3628a56-6f85-43b5-be50-71d8f0e04877.root.2023-08-31T02_59_24Z.010479.log"]); | ||
|
|
||
| let extra = sort_cockroach_extra_logs(logs.as_slice()); | ||
| assert_eq!( | ||
|
|
@@ -1177,6 +1177,12 @@ mod illumos_tests { | |
| let mut logfile_handle = | ||
| fs_err::tokio::File::create_new(&logfile).await.unwrap(); | ||
| logfile_handle.write_all(data.as_bytes()).await.unwrap(); | ||
|
|
||
| // 2025-10-15T00:00:00 | ||
| let mtime = std::time::SystemTime::UNIX_EPOCH | ||
| + std::time::Duration::from_secs(1760486400); | ||
| let std_file = logfile_handle.into_std().await.into_file(); | ||
| std_file.set_modified(mtime).unwrap(); | ||
| } | ||
|
|
||
| // Populate some file with similar names that should be skipped over | ||
|
|
@@ -1197,27 +1203,40 @@ mod illumos_tests { | |
| let zipfile_path = mountpoint.join("test.zip"); | ||
| let zipfile = File::create_new(&zipfile_path).unwrap(); | ||
| let mut zip = ZipWriter::new(zipfile); | ||
| let log = LogFile { | ||
| path: mountpoint | ||
| .join(format!("var/svc/log/{}", logfile_to_data[0].0)), | ||
| size: None, | ||
| modified: None, | ||
| }; | ||
|
|
||
| loghandle | ||
| .process_logs( | ||
| "mg-ddm", | ||
| &mut zip, | ||
| &mut log_snapshots, | ||
| &log, | ||
| LogType::Current, | ||
| ) | ||
| .await | ||
| .unwrap(); | ||
|
|
||
| zip.finish().unwrap(); | ||
|
|
||
| let expected_zip_mtime = | ||
| zip::DateTime::from_date_and_time(2025, 10, 15, 0, 0, 0) | ||
| .unwrap(); | ||
|
|
||
| // Confirm the zip has our file and data with the right mtime | ||
| let mut archive = | ||
| ZipArchive::new(File::open(zipfile_path).unwrap()).unwrap(); | ||
| for (name, data) in logfile_to_data { | ||
| let mut file_in_zip = | ||
| archive.by_name(&format!("mg-ddm/current/{name}")).unwrap(); | ||
|
|
||
| let mtime = file_in_zip.last_modified().unwrap(); | ||
| assert_eq!(mtime, expected_zip_mtime, "file mtime matches"); | ||
|
|
||
| let mut contents = String::new(); | ||
| file_in_zip.read_to_string(&mut contents).unwrap(); | ||
|
|
||
|
|
@@ -1283,13 +1302,14 @@ mod illumos_tests { | |
| let zipfile_path = mountpoint.join("test.zip"); | ||
| let zipfile = File::create_new(&zipfile_path).unwrap(); | ||
| let mut zip = ZipWriter::new(zipfile); | ||
| let log = LogFile { path: logfile, size: None, modified: None }; | ||
|
|
||
| loghandle | ||
| .process_logs( | ||
| "mg-ddm", | ||
| &mut zip, | ||
| &mut log_snapshots, | ||
| &log, | ||
| LogType::Current, | ||
| ) | ||
| .await | ||
|
|
||
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Two questions about this...
Should we ignore errors here so that we still include files that we fail to read an mtime from and continue collecting the bundle?
Since we are getting the logs in a zip file and then unpacking them on a sled where a bundle is being collected are we sure that the unzip process is preserving original modification times? I believe it does hence the entire point of this PR haha but it would be good to maybe test that the zip crate is doing this.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Makes sense, since
mtimeis just a nice to have. Updated in 72d5f84Yes, but it's good to be sure. I modified
app::background::tasks::support_bundle_collector::test::test_collect_chunkedto write out the bundle:The
mtimeof files in the zip are set as expected: