Skip to content

Commit ffd85b9

Browse files
vmagrometa-codesync[bot]
authored andcommitted
[antlir2][image_test] log booted test stdout/err as tpx artifact
Summary: Instead of simply copying this when the test finishes (successfully or failed), also upload it as a TPX artifact so that it's always visible in the UI on any kind of test failure. Test Plan: ```name="Make a test that times out while printing stuff" ❯ hg diff diff --git a/fbcode/antlir/antlir2/testing/tests/test.py b/fbcode/antlir/antlir2/testing/tests/test.py --- a/fbcode/antlir/antlir2/testing/tests/test.py +++ b/fbcode/antlir/antlir2/testing/tests/test.py @@ -8,6 +8,8 @@ import os import pwd import stat +import sys +import time import unittest @@ -33,3 +35,9 @@ os.makedev(1, 3), "/dev/null device number is wrong", ) + + def test_timeout(self) -> None: + while True: + print("running...") + print("running...", file=sys.stderr) + time.sleep(1) ``` ``` ❯ buck2 test fbcode//antlir/antlir2/testing/tests:test-py-boot-centos9 -- timeout --timeout=5 ✉ Timeout: fbcode//antlir/antlir2/testing/tests:test-py-boot-centos9 - test_timeout (antlir.antlir2.testing.tests.test.Test) (5.0s) Your test timed out because its execution time exceeded 5 seconds. Profile your test to understand what makes it slow stdout: from_execution_error::timeout::Buck2TpxTimeout stderr: Buck UI: https://www.internalfb.com/buck2/79de5265-756f-4e6e-b737-ec829da3cb40 Test UI: https://www.internalfb.com/intern/testinfra/testrun/5910974838205890 Network: Up: 0B Down: 0B Analyzing targets. Remaining 0/153 Executing actions. Remaining 0/364 Command: test. Time elapsed: 7.8s Test execution completed but the tests failed Tests finished: Pass 0. Fail 1. Fatal 0. Skip 0. Infra Failure 0. Build failure 0 1 TESTS FAILED ✗ fbcode//antlir/antlir2/testing/tests:test-py-boot-centos9 - test_timeout (antlir.antlir2.testing.tests.test.Test) ``` But it's visible in the UI: https://pxl.cl/8wvxq Reviewed By: justintrudell Differential Revision: D88067169 fbshipit-source-id: cade40784d38c285e542a50c9d79766ca5ba9ad8
1 parent 45b1a6d commit ffd85b9

File tree

3 files changed

+131
-52
lines changed

3 files changed

+131
-52
lines changed

antlir/antlir2/testing/image_test/BUCK

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,14 +9,19 @@ rust_library(
99
srcs = ["src/lib.rs"],
1010
visibility = ["PUBLIC"],
1111
deps = [
12+
"anyhow",
1213
"clap",
14+
"tempfile",
1315
"thiserror",
1416
],
1517
)
1618

1719
rust_binary(
1820
name = "image-test",
19-
srcs = glob(["src/**/*.rs"]),
21+
srcs = glob(
22+
["src/**/*.rs"],
23+
exclude = ["src/lib.rs"],
24+
),
2025
crate_root = "src/main.rs",
2126
resources = {
2227
"antlir2_image_test_shell.conf": "antlir2_image_test_shell.conf",

antlir/antlir2/testing/image_test/src/lib.rs

Lines changed: 113 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,11 +8,18 @@
88
use std::collections::HashSet;
99
use std::ffi::OsStr;
1010
use std::ffi::OsString;
11+
use std::fs::File;
12+
use std::fs::OpenOptions;
13+
use std::os::fd::AsRawFd;
14+
use std::os::fd::FromRawFd;
1115
use std::path::Path;
1216
use std::path::PathBuf;
1317
use std::str::FromStr;
1418

19+
use anyhow::Context;
20+
use anyhow::Result;
1521
use clap::Parser;
22+
use tempfile::NamedTempFile;
1623
use thiserror::Error;
1724

1825
#[derive(Parser, Clone, Debug)]
@@ -225,6 +232,112 @@ impl KvPair {
225232
}
226233
}
227234

235+
/// A file that tpx will upload as an artifact on failing test instances. If not
236+
/// run under tpx, this will be some other fd (a regular file in /tmp, stderr, etc)
237+
pub struct TpxArtifact {
238+
file: LogFile,
239+
path: PathBuf,
240+
}
241+
242+
enum LogFile {
243+
Stderr,
244+
File(File),
245+
Tmp(NamedTempFile),
246+
}
247+
248+
impl TpxArtifact {
249+
/// Create a file to record additional text logs into. When invoked under
250+
/// tpx, this will be uploaded as an artifact. The artifact metadata is set
251+
/// up before running the test so that it still gets uploaded even in case
252+
/// of a timeout.
253+
/// If not running under tpx, this will be sent to stderr
254+
fn new_tpx_or_none(name: &str) -> Result<Option<Self>> {
255+
// if tpx has provided this artifacts dir, put the logs there so they get
256+
// uploaded along with the test results
257+
if let Some(artifacts_dir) = std::env::var_os("TEST_RESULT_ARTIFACTS_DIR") {
258+
std::fs::create_dir_all(&artifacts_dir).with_context(|| {
259+
format!("while creating artifacts dir {}", artifacts_dir.display())
260+
})?;
261+
let dst = Path::new(&artifacts_dir).join(name);
262+
if let Some(annotations_dir) = std::env::var_os("TEST_RESULT_ARTIFACT_ANNOTATIONS_DIR")
263+
{
264+
std::fs::create_dir_all(&annotations_dir)?;
265+
std::fs::write(
266+
Path::new(&annotations_dir).join(format!("{name}.annotation")),
267+
r#"{"type": {"generic_text_log": {}}, "description": "test logs"}"#,
268+
)?;
269+
}
270+
let file = OpenOptions::new()
271+
.create(true)
272+
.truncate(true)
273+
.read(true)
274+
.write(true)
275+
.open(&dst)
276+
.with_context(|| format!("while creating {}", dst.display()))?;
277+
Ok(Some(Self {
278+
file: LogFile::File(file),
279+
path: dst,
280+
}))
281+
} else {
282+
Ok(None)
283+
}
284+
}
285+
286+
/// Create a file to record additional text logs into. When invoked under
287+
/// tpx, this will be uploaded as an artifact. The artifact metadata is set
288+
/// up before running the test so that it still gets uploaded even in case
289+
/// of a timeout.
290+
/// If not running under tpx, this will be sent to a temporary file.
291+
pub fn new_log_file(name: &str) -> Result<Self> {
292+
match Self::new_tpx_or_none(name)? {
293+
Some(s) => Ok(s),
294+
None => {
295+
let tmpfile = tempfile::NamedTempFile::new()?;
296+
Ok(Self {
297+
path: tmpfile.path().to_owned(),
298+
file: LogFile::Tmp(tmpfile),
299+
})
300+
}
301+
}
302+
}
303+
304+
/// Same as [TpxArtifact::new_log_file], but if not running under tpx, this
305+
/// will be sent to stderr
306+
pub fn new_log_file_or_stderr(name: &str) -> Result<Self> {
307+
match Self::new_tpx_or_none(name)? {
308+
Some(s) => Ok(s),
309+
None => Ok(Self {
310+
file: LogFile::Stderr,
311+
path: "/dev/stderr".into(),
312+
}),
313+
}
314+
}
315+
316+
pub fn as_file(&self) -> std::io::Result<File> {
317+
match &self.file {
318+
LogFile::Stderr => Ok(unsafe { File::from_raw_fd(std::io::stderr().as_raw_fd()) }),
319+
LogFile::File(f) => f.try_clone(),
320+
LogFile::Tmp(f) => f.as_file().try_clone(),
321+
}
322+
}
323+
324+
pub fn into_file(self) -> File {
325+
match self.file {
326+
LogFile::Stderr => unsafe { File::from_raw_fd(std::io::stderr().as_raw_fd()) },
327+
LogFile::File(f) => f,
328+
LogFile::Tmp(f) => f.into_file(),
329+
}
330+
}
331+
332+
pub fn is_stderr(&self) -> bool {
333+
matches!(self.file, LogFile::Stderr)
334+
}
335+
336+
pub fn path(&self) -> &Path {
337+
&self.path
338+
}
339+
}
340+
228341
#[cfg(test)]
229342
mod test {
230343
use std::env;

antlir/antlir2/testing/image_test/src/spawn_common.rs

Lines changed: 12 additions & 51 deletions
Original file line numberDiff line numberDiff line change
@@ -7,11 +7,9 @@
77

88
use std::collections::BTreeMap;
99
use std::collections::HashMap;
10-
use std::fs::File;
1110
use std::fs::Permissions;
11+
use std::io::Seek;
1212
use std::io::Write;
13-
use std::os::fd::AsRawFd;
14-
use std::os::fd::FromRawFd;
1513
use std::os::unix::fs::PermissionsExt;
1614
use std::os::unix::process::CommandExt;
1715
use std::path::Path;
@@ -27,17 +25,14 @@ use anyhow::Result;
2725
use anyhow::ensure;
2826
use bon::builder;
2927
use image_test_lib::Test;
28+
use image_test_lib::TpxArtifact;
3029
use tempfile::NamedTempFile;
3130
use tracing::debug;
3231
use tracing::trace;
3332

3433
use crate::exec;
3534
use crate::runtime;
3635

37-
fn make_log_files(_base: &str) -> Result<(NamedTempFile, NamedTempFile)> {
38-
Ok((NamedTempFile::new()?, NamedTempFile::new()?))
39-
}
40-
4136
#[builder]
4237
pub(crate) fn run(
4338
spec: runtime::Spec,
@@ -143,8 +138,9 @@ pub(crate) fn run(
143138

144139
match spec.boot {
145140
Some(boot) => {
146-
let container_stdout = container_stdout_file()?;
147-
let (mut test_stdout, mut test_stderr) = make_log_files("test")?;
141+
let container_stdout = TpxArtifact::new_log_file_or_stderr("container-stdout.txt")?;
142+
let test_stdout = TpxArtifact::new_log_file("test-stdout.txt")?;
143+
let test_stderr = TpxArtifact::new_log_file("test-stderr.txt")?;
148144

149145
let mut test_unit_dropin = NamedTempFile::new()?;
150146
writeln!(test_unit_dropin, "[Unit]")?;
@@ -255,18 +251,22 @@ pub(crate) fn run(
255251
.context("while spawning systemd-nspawn")?;
256252
let res = child.wait().context("while waiting for systemd-nspawn")?;
257253

254+
let mut test_stdout = test_stdout.into_file();
255+
let mut test_stderr = test_stderr.into_file();
256+
test_stdout.rewind()?;
257+
test_stderr.rewind()?;
258258
std::io::copy(&mut test_stdout, &mut std::io::stdout())?;
259259
std::io::copy(&mut test_stderr, &mut std::io::stderr())?;
260260

261261
if !res.success() {
262262
// if the container stdout is not already being dumped to
263263
// stdout/err, then print out the path where it can be found
264-
if let ContainerConsoleOutput::File { path, .. } = &container_stdout {
264+
if !container_stdout.is_stderr() {
265265
eprintln!(
266266
"full container console output can be found at: '{}'",
267-
path.display()
267+
container_stdout.path().display()
268268
);
269-
eprintln!("{}", path.display());
269+
eprintln!("{}", container_stdout.path().display());
270270
}
271271
std::process::exit(res.code().unwrap_or(255))
272272
} else {
@@ -289,42 +289,3 @@ pub(crate) fn run(
289289
}
290290
}
291291
}
292-
293-
enum ContainerConsoleOutput {
294-
File { path: PathBuf, file: File },
295-
Stderr,
296-
}
297-
298-
impl ContainerConsoleOutput {
299-
fn as_file(&self) -> Result<File> {
300-
match self {
301-
Self::File { file, .. } => file.try_clone().context("while cloning file fd"),
302-
Self::Stderr => Ok(unsafe { File::from_raw_fd(std::io::stderr().as_raw_fd()) }),
303-
}
304-
}
305-
}
306-
307-
/// Create a file to record container stdout into. When invoked under tpx, this
308-
/// will be uploaded as an artifact. The artifact metadata is set up before
309-
/// running the test so that it still gets uploaded even in case of a timeout
310-
fn container_stdout_file() -> Result<ContainerConsoleOutput> {
311-
// if tpx has provided this artifacts dir, put the logs there so they get
312-
// uploaded along with the test results
313-
if let Some(artifacts_dir) = std::env::var_os("TEST_RESULT_ARTIFACTS_DIR") {
314-
std::fs::create_dir_all(&artifacts_dir)?;
315-
let dst = Path::new(&artifacts_dir).join("container-stdout.txt");
316-
if let Some(annotations_dir) = std::env::var_os("TEST_RESULT_ARTIFACT_ANNOTATIONS_DIR") {
317-
std::fs::create_dir_all(&annotations_dir)?;
318-
std::fs::write(
319-
Path::new(&annotations_dir).join("container-stdout.txt.annotation"),
320-
r#"{"type": {"generic_text_log": {}}, "description": "systemd logs"}"#,
321-
)?;
322-
}
323-
File::create(&dst)
324-
.with_context(|| format!("while creating {}", dst.display()))
325-
.map(|file| ContainerConsoleOutput::File { path: dst, file })
326-
} else {
327-
// otherwise, have it go right to stderr
328-
Ok(ContainerConsoleOutput::Stderr)
329-
}
330-
}

0 commit comments

Comments
 (0)