Skip to content

Commit 6e576ef

Browse files
vmagrometa-codesync[bot]
authored andcommitted
[antlir2_vm] expose sidecar, tgtd and iSCSI connection logs to postmortem tests
Summary: Postmortem tests previously only got $CONSOLE_OUTPUT (QEMU console). Host-side services like sidecar services (images-sidecar) and tgtd (iSCSI target daemon) ran in the container but their logs were not durable and not exposed to postmortem. This enables black-box testing of the exitrd path: boot iscsi-root-vm (pure iSCSI root, no local disk), poweroff via expect_vm_exit, then postmortem checks that tgtd saw a clean logout (no lingering connections). This verifies that the exitrd itself performed the logout, rather than white-box calling the same logout script inside the guest. Test Plan: ``` buck2 test fbcode//mode/opt fbcode//metalos/vm/tests/antlir:test-sidecar-logs Buck UI: https://www.internalfb.com/buck2/3b3512fe-e7ba-4b7c-95bb-28ccb2a7b5f5 Tests finished: Pass 2. Fail 0. Timeout 0. Fatal 0. Skip 0. Omit 0. Infra Failure 0. Build failure 0 ``` https://www.internalfb.com/intern/testinfra/testrun/7036874785957793 Reviewed By: joshuamiller01 Differential Revision: D115265010 fbshipit-source-id: 732ac80d7180332dfc33662c552bee3a7a5b436e
1 parent c5d0b45 commit 6e576ef

5 files changed

Lines changed: 315 additions & 87 deletions

File tree

antlir/antlir2/antlir2_vm/src/iscsi.rs

Lines changed: 28 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@
66
*/
77

88
use std::path::Path;
9+
use std::path::PathBuf;
910
use std::process::Child;
1011
use std::process::Command;
1112
use std::thread;
@@ -15,6 +16,7 @@ use thiserror::Error;
1516
use tracing::debug;
1617

1718
use crate::utils::log_command;
19+
use crate::utils::redirect_output_to_file;
1820
use crate::utils::run_command_capture_output;
1921

2022
pub(crate) const TGTD_PORTAL: &str = "[::]:3260";
@@ -32,6 +34,10 @@ pub(crate) enum IscsiError {
3234
TgtdReadyTimeout,
3335
#[error("tgtadm failed: {0}")]
3436
TgtadmError(std::io::Error),
37+
#[error("Failed to open tgtd log file {path}: {err}")]
38+
TgtdLogError { path: PathBuf, err: std::io::Error },
39+
#[error("Failed to list iSCSI connections: {0}")]
40+
ListConnectionsError(std::io::Error),
3541
}
3642

3743
type Result<T> = std::result::Result<T, IscsiError>;
@@ -56,25 +62,44 @@ impl Drop for IscsiTargetDaemon {
5662
}
5763

5864
impl IscsiTargetDaemon {
59-
pub(crate) fn start(state_dir: &Path) -> Result<Self> {
60-
let process = Self::start_tgtd(state_dir)?;
65+
pub(crate) fn start(state_dir: &Path, logs_dir: Option<&Path>) -> Result<Self> {
66+
let process = Self::start_tgtd(state_dir, logs_dir)?;
6167
Self::wait_for_ready()?;
6268
Ok(Self { process })
6369
}
6470

65-
fn start_tgtd(state_dir: &Path) -> Result<Child> {
71+
fn start_tgtd(state_dir: &Path, logs_dir: Option<&Path>) -> Result<Child> {
6672
let pid_file = state_dir.join("tgtd.pid");
6773
let mut cmd = Command::new("tgtd");
6874
cmd.arg("--foreground")
6975
.arg("--iscsi")
7076
.arg(format!("portal={TGTD_PORTAL}"))
7177
.arg("--pid-file")
7278
.arg(&pid_file);
79+
if let Some(dir) = logs_dir {
80+
let path = dir.join("tgtd.log");
81+
redirect_output_to_file(&mut cmd, &path)
82+
.map_err(|err| IscsiError::TgtdLogError { path, err })?;
83+
}
7384
log_command(&mut cmd)
7485
.spawn()
7586
.map_err(IscsiError::TgtdStartError)
7687
}
7788

89+
/// Current iSCSI connections as reported by `tgtadm`. Both output streams
90+
/// are returned since this is only ever read by a human debugging a test.
91+
pub(crate) fn list_connections() -> Result<String> {
92+
let output = Command::new("tgtadm")
93+
.args(["--lld", "iscsi", "--mode", "conn", "--op", "show"])
94+
.output()
95+
.map_err(IscsiError::ListConnectionsError)?;
96+
Ok(format!(
97+
"{}{}",
98+
String::from_utf8_lossy(&output.stdout),
99+
String::from_utf8_lossy(&output.stderr)
100+
))
101+
}
102+
78103
fn wait_for_ready() -> Result<()> {
79104
for _ in 0..50 {
80105
let result = Command::new("tgtadm")

antlir/antlir2/antlir2_vm/src/main.rs

Lines changed: 46 additions & 32 deletions
Original file line numberDiff line numberDiff line change
@@ -46,13 +46,15 @@ use tracing_subscriber::prelude::*;
4646
use crate::isolation::Platform;
4747
use crate::isolation::isolated;
4848
use crate::share::VirtiofsShare;
49+
use crate::types::CONSOLE_LOG;
4950
use crate::types::MachineOpts;
5051
use crate::types::MountPlatformDecision;
5152
use crate::types::VMArgs;
5253
use crate::utils::create_tpx_blobs;
5354
use crate::utils::create_tpx_logs;
5455
use crate::utils::env_names_to_kvpairs;
5556
use crate::utils::log_command;
57+
use crate::utils::tpx_artifacts_dir;
5658
use crate::vm::VM;
5759
use crate::vm::VMError;
5860

@@ -119,15 +121,22 @@ fn run(args: &RunCmdArgs) -> Result<()> {
119121

120122
let mut vm_args = args.vm_args.clone();
121123
if args.postmortem {
122-
if args.vm_args.console_output_file.is_none() {
123-
bail!("Console output file must be specified to run command after VM termination.");
124+
if args.vm_args.logs_dir.is_none() {
125+
bail!("logs_dir must be specified to run command after VM termination.");
124126
}
125127
if args.vm_args.mode.command.is_none() {
126128
bail!("Expected to run command after VM termination but no command specified.");
127129
}
128-
// Don't run the test command inside the VM. Hijack it with our stub so we shut it down as
129-
// soon as default target is reached.
130-
vm_args.mode.command = Some(vec!["sh".into(), "-c".into(), "exit".into()]);
130+
// A postmortem test runs on the host, so it must never be handed to the
131+
// guest. Hijack the guest command with a stub that just returns, which
132+
// leaves the VM at its default target for us to tear down - unless the
133+
// test wants to observe a guest-initiated shutdown, in which case the
134+
// stub has to arm ACPI S5 instead. `--no-block` is what lets the ssh
135+
// session close cleanly before systemd starts shutting down.
136+
vm_args.mode.command = Some(match vm_args.expect_vm_exit {
137+
Some(_) => vec!["systemctl".into(), "poweroff".into(), "--no-block".into()],
138+
None => vec!["sh".into(), "-c".into(), "exit".into()],
139+
});
131140
}
132141

133142
let machine_opts = args.machine_spec.clone().into_inner();
@@ -160,13 +169,15 @@ fn run(args: &RunCmdArgs) -> Result<()> {
160169
args.vm_args.command_envs.iter().for_each(|pair| {
161170
cmd.env(&pair.key, &pair.value);
162171
});
163-
cmd.env(
164-
"CONSOLE_OUTPUT",
165-
args.vm_args
166-
.console_output_file
167-
.as_ref()
168-
.expect("No console output file"),
169-
);
172+
let logs_dir = args
173+
.vm_args
174+
.logs_dir
175+
.as_ref()
176+
.expect("logs_dir is checked above for postmortem");
177+
// Tests find per-process logs by binary name, e.g.
178+
// $SIDECAR_LOGS_DIR/tgtd.log.
179+
cmd.env("CONSOLE_OUTPUT", logs_dir.join(CONSOLE_LOG));
180+
cmd.env("SIDECAR_LOGS_DIR", logs_dir);
170181
cmd_args.iter().skip(1).for_each(|arg| {
171182
cmd.arg(arg);
172183
});
@@ -192,12 +203,12 @@ fn respawn(args: &IsolateCmdArgs) -> Result<()> {
192203
let envs = env_names_to_kvpairs(args.passenv.clone());
193204
vm_args.command_envs = envs.clone();
194205

195-
// Let's always capture console output unless it's console mode
196-
let _console_dir;
197-
if !vm_args.mode.console && vm_args.console_output_file.is_none() {
198-
let dir = tempdir().context("Failed to create temp dir for console output")?;
199-
vm_args.console_output_file = Some(dir.path().join("console.txt"));
200-
_console_dir = dir;
206+
// Let's always capture logs unless it's console mode.
207+
let _logs_dir;
208+
if !vm_args.mode.console && vm_args.logs_dir.is_none() {
209+
let dir = tempdir().context("Failed to create temp dir for logs")?;
210+
vm_args.logs_dir = Some(dir.path().to_path_buf());
211+
_logs_dir = dir;
201212
}
202213

203214
antlir2_rootless::unshare_new_userns()?;
@@ -314,24 +325,20 @@ fn get_test_vm_args(
314325
}
315326
vm_args.mode.command = Some(test_args.test.into_inner_cmd());
316327
vm_args.command_envs = envs;
317-
// Only auto-route the console to tpx artifacts if the caller didn't
318-
// already specify --console-output-file. This lets `buck2 run` consumers
319-
// (e.g. skycastle workflows) persist guest console output to an arbitrary
320-
// path without being silently overridden.
321-
if vm_args.console_output_file.is_none() {
322-
vm_args.console_output_file = create_tpx_logs("console.txt", "console logs")?;
328+
// Collect logs straight into the tpx artifacts dir so that everything
329+
// written there is uploaded and inspectable on failure.
330+
if vm_args.logs_dir.is_none() {
331+
create_tpx_logs(CONSOLE_LOG, "console logs")?;
332+
vm_args.logs_dir = tpx_artifacts_dir();
323333
}
324334
if dump_eth0_traffic {
325335
vm_args.eth0_output_file = create_tpx_blobs("eth0.pcap", "eth0 traffic")?;
326336
}
327-
if let Some(console_output_dir) = vm_args
328-
.console_output_file
329-
.as_ref()
330-
.and_then(|f| f.parent())
331-
{
332-
vm_args
333-
.output_dirs
334-
.push(console_output_dir.to_owned().canonicalize()?);
337+
if let Some(logs_dir) = &vm_args.logs_dir {
338+
let canonical = logs_dir.canonicalize().unwrap_or_else(|_| logs_dir.clone());
339+
if !vm_args.output_dirs.contains(&canonical) {
340+
vm_args.output_dirs.push(canonical);
341+
}
335342
}
336343
Ok(ValidatedVMArgs {
337344
inner: vm_args,
@@ -449,6 +456,13 @@ fn test(args: &IsolateCmdArgs) -> Result<()> {
449456
args.passenv.clone(),
450457
args.dump_eth0_traffic,
451458
)?;
459+
460+
// Annotate every host-side log up front so tpx uploads it even if the
461+
// producing process never writes anything.
462+
for log in machine_spec.host_log_files() {
463+
create_tpx_logs(&log.name, &log.description)?;
464+
}
465+
452466
antlir2_rootless::unshare_new_userns()?;
453467
antlir2_isolate::unshare_and_privatize_mount_ns().context("while isolating mount ns")?;
454468

0 commit comments

Comments
 (0)