Skip to content

Commit 0f0e9e7

Browse files
committed
test: add integration test for instrumented Firecracker binary
Adds a new integration test that verifies Firecracker can be built and run with `log_instrument` tracing instrumentation\ enabled. Signed-off-by: DontPanicO <[email protected]>
1 parent f5c2674 commit 0f0e9e7

File tree

1 file changed

+134
-0
lines changed

1 file changed

+134
-0
lines changed
Lines changed: 134 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,134 @@
1+
# Copyright 2025 Amazon.com, Inc. or its affiliates. All Rights Reserved.
2+
# SPDX-License-Identifier: Apache-2.0
3+
4+
"""
5+
Integration test verifying that Firecracker builds and runs correctly when instrumented
6+
with the `log_instrument::instrument` macro. Ensures that TRACE-level logs and entry/exit
7+
markers (ThreadId(...) >> / <<) are emitted when the binary is built with the `tracing`
8+
feature.
9+
"""
10+
11+
import platform
12+
import re
13+
from pathlib import Path
14+
15+
import pytest
16+
17+
from framework import utils
18+
from host_tools.cargo_build import cargo, get_binary
19+
20+
# Typical markers emitted by the `log_instrument` macro
21+
TRACE_LEVEL_HINT = "TRACE"
22+
MARKER_REGEX = re.compile(r"ThreadId\(\d+\).*?(?:>>|<<)")
23+
PATHS_TO_INSTRUMENT = [
24+
"../src/firecracker/src/main.rs",
25+
"../src/firecracker/src/api_server",
26+
"../src/vmm/src/lib.rs",
27+
"../src/vmm/src/builder.rs",
28+
]
29+
TMP_BUILD_DIR = "../test_instrumented_firecracker_build"
30+
ARCH_STR = f"{platform.machine()}"
31+
32+
33+
def build_instrumented_binary():
34+
"""Builds an instrumented Firecracker binary with tracing instrumentation."""
35+
# we need a different directory to avoid overriding the main bin
36+
instrumented_binary_dir = (
37+
Path(TMP_BUILD_DIR) / f"{ARCH_STR}-unknown-linux-musl" / "release"
38+
)
39+
40+
clippy_tracing = get_binary("clippy-tracing")
41+
for p in PATHS_TO_INSTRUMENT:
42+
utils.check_output(
43+
f"{clippy_tracing} --action fix --suffix log_instrument:: --cfg-attr 'feature =\"tracing\"' --path {p}"
44+
)
45+
cargo(
46+
"build",
47+
f"--workspace --target {platform.machine()}-unknown-linux-musl --release "
48+
f"--features tracing --bin firecracker",
49+
env={"CARGO_TARGET_DIR": TMP_BUILD_DIR},
50+
)
51+
return get_binary("firecracker", binary_dir=instrumented_binary_dir)
52+
53+
54+
def cleanup_instrumentation():
55+
"""Cleans up tracing instrumentation from the Firecracker binary."""
56+
clippy_tracing = get_binary("clippy-tracing")
57+
for p in PATHS_TO_INSTRUMENT:
58+
utils.check_output(
59+
f"{clippy_tracing} --action strip --suffix log_instrument:: --cfg-attr 'feature =\"tracing\"' --path {p}"
60+
)
61+
62+
63+
@pytest.fixture(scope="module")
64+
def instrumented_binary():
65+
"""Build and provide the path to an instrumented Firecracker binary."""
66+
binary_path = build_instrumented_binary()
67+
yield binary_path
68+
cleanup_instrumentation()
69+
70+
71+
@pytest.mark.timeout(120)
72+
def test_log_instrument_firecracker_basic_functionality(
73+
instrumented_binary, microvm_factory
74+
):
75+
"""Test that instrumented Firecracker can start and handle basic API calls with trace logging."""
76+
vm = microvm_factory.build(fc_binary_path=instrumented_binary)
77+
vm.spawn(log_level="Info", log_show_level=True, log_show_origin=True)
78+
79+
# Generate some log traffic
80+
_ = vm.api.describe.get()
81+
_ = vm.api.machine_config.get()
82+
83+
pre_tracing_log_data = vm.log_data
84+
85+
# Ensure TRACE logs are being captured
86+
logger_config = {
87+
"level": "Trace",
88+
"show_level": True,
89+
"show_log_origin": True,
90+
}
91+
_ = vm.api.logger.put(**logger_config)
92+
93+
# Another API call after enabling TRACE
94+
_ = vm.api.describe.get()
95+
96+
assert (
97+
TRACE_LEVEL_HINT not in pre_tracing_log_data
98+
), "TRACE level logs were found before setting log level to TRACE. "
99+
100+
pre_tracing_log_matches = re.findall(MARKER_REGEX, pre_tracing_log_data)
101+
102+
assert (
103+
len(pre_tracing_log_matches) == 0
104+
), f"Expected no log-instrument traces in logs before enabling TRACE, but found: {pre_tracing_log_matches}"
105+
106+
post_tracing_log_data = vm.log_data
107+
108+
assert (
109+
TRACE_LEVEL_HINT in post_tracing_log_data
110+
), "Expected TRACE level logs in output"
111+
112+
post_tracing_log_matches = re.findall(MARKER_REGEX, post_tracing_log_data)
113+
114+
assert (
115+
len(post_tracing_log_matches) > 0
116+
), f"Expected to find log-instrument traces in logs, but found none. Log data: {post_tracing_log_data[:1000]}..."
117+
118+
entry_traces = [match for match in post_tracing_log_matches if ">>" in match]
119+
exit_traces = [match for match in post_tracing_log_matches if "<<" in match]
120+
121+
assert len(entry_traces) > 0, "Expected to find function entry traces (>>)"
122+
assert len(exit_traces) > 0, "Expected to find function exit traces (<<)"
123+
124+
meaningful_keywords = ["vmm", "request", "response"]
125+
126+
# Ensure that each of the meaningful keywords is present in at least one trace
127+
# match from the post-tracing logs.
128+
assert all(
129+
any(keyword.lower() in trace.lower() for trace in post_tracing_log_matches)
130+
for keyword in meaningful_keywords
131+
), (
132+
f"Expected to find traces from meaningful keywords {meaningful_keywords}, "
133+
f"but traces were: {post_tracing_log_matches[:10]}..."
134+
)

0 commit comments

Comments
 (0)