|
| 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 re |
| 12 | +import tempfile |
| 13 | + |
| 14 | +import pytest |
| 15 | + |
| 16 | +from framework import utils |
| 17 | +from framework.microvm import MicroVMFactory |
| 18 | +from host_tools.cargo_build import cargo, get_binary |
| 19 | + |
| 20 | +# Marker tipici emessi dalla macro log_instrument |
| 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 | + |
| 30 | + |
| 31 | +def build_instrumented_binary(): |
| 32 | + """Builds an instrumented Firecracker binary with tracing instrumentation.""" |
| 33 | + clippy_tracing = get_binary("clippy-tracing") |
| 34 | + for p in PATHS_TO_INSTRUMENT: |
| 35 | + utils.check_output( |
| 36 | + f"{clippy_tracing} --action fix --suffix log_instrument:: --cfg-attr 'feature =\"tracing\"' --path {p}" |
| 37 | + ) |
| 38 | + cargo( |
| 39 | + "build", |
| 40 | + "--workspace --target x86_64-unknown-linux-musl --no-default-features --release --features tracing --bin firecracker", |
| 41 | + ) |
| 42 | + return get_binary("firecracker") |
| 43 | + |
| 44 | + |
| 45 | +def cleanup_instrumentation(): |
| 46 | + """Cleans up tracing instrumentation from the Firecracker binary.""" |
| 47 | + clippy_tracing = get_binary("clippy-tracing") |
| 48 | + for p in PATHS_TO_INSTRUMENT: |
| 49 | + utils.check_output( |
| 50 | + f"{clippy_tracing} --action strip --suffix log_instrument:: --cfg-attr 'feature =\"tracing\"' --path {p}" |
| 51 | + ) |
| 52 | + |
| 53 | + |
| 54 | +@pytest.fixture(scope="module") |
| 55 | +def instrumented_binary(): |
| 56 | + """Build and provide the path to an instrumented Firecracker binary.""" |
| 57 | + binary_path = build_instrumented_binary() |
| 58 | + yield binary_path |
| 59 | + cleanup_instrumentation() |
| 60 | + |
| 61 | + |
| 62 | +@pytest.mark.timeout(120) |
| 63 | +def test_log_instrument_firecracker_basic_functionality(instrumented_binary): |
| 64 | + """Test that instrumented Firecracker can start and handle basic API calls with trace logging.""" |
| 65 | + with tempfile.TemporaryDirectory() as _: |
| 66 | + microvm_factory = MicroVMFactory(instrumented_binary.parent) |
| 67 | + vm = microvm_factory.build() |
| 68 | + vm.spawn(log_level="Trace", log_show_level=True, log_show_origin=True) |
| 69 | + |
| 70 | + try: |
| 71 | + vm._wait_for_api_socket() |
| 72 | + |
| 73 | + # Generate some log traffic |
| 74 | + resp = vm.api.describe.get() |
| 75 | + assert resp.status_code == 200 |
| 76 | + resp = vm.api.machine_config.get() |
| 77 | + assert resp.status_code == 200 |
| 78 | + |
| 79 | + # Ensure TRACE logs are being captured |
| 80 | + logger_config = { |
| 81 | + "level": "Trace", |
| 82 | + "show_level": True, |
| 83 | + "show_log_origin": True, |
| 84 | + } |
| 85 | + resp = vm.api.logger.put(**logger_config) |
| 86 | + assert resp.status_code == 204 |
| 87 | + |
| 88 | + # Another API call after enabling TRACE |
| 89 | + resp = vm.api.describe.get() |
| 90 | + assert resp.status_code == 200 |
| 91 | + |
| 92 | + finally: |
| 93 | + vm.kill() |
| 94 | + |
| 95 | + log_data = vm.log_data |
| 96 | + assert TRACE_LEVEL_HINT in log_data, "Expected TRACE level logs in output" |
| 97 | + |
| 98 | + trace_matches = re.findall(MARKER_REGEX, log_data) |
| 99 | + |
| 100 | + assert ( |
| 101 | + len(trace_matches) > 0 |
| 102 | + ), f"Expected to find log-instrument traces in logs, but found none. Log data: {log_data[:1000]}..." |
| 103 | + |
| 104 | + entry_traces = [match for match in trace_matches if ">>" in match] |
| 105 | + exit_traces = [match for match in trace_matches if "<<" in match] |
| 106 | + |
| 107 | + assert len(entry_traces) > 0, "Expected to find function entry traces (>>)" |
| 108 | + assert len(exit_traces) > 0, "Expected to find function exit traces (<<)" |
| 109 | + |
| 110 | + meaningful_functions = ["main", "api", "vmm", "request", "response"] |
| 111 | + found_meaningful = False |
| 112 | + |
| 113 | + for trace in trace_matches: |
| 114 | + for func in meaningful_functions: |
| 115 | + if func.lower() in trace.lower(): |
| 116 | + found_meaningful = True |
| 117 | + break |
| 118 | + if found_meaningful: |
| 119 | + break |
| 120 | + |
| 121 | + assert ( |
| 122 | + found_meaningful |
| 123 | + ), f"Expected to find traces from meaningful functions, but traces were: {trace_matches[:10]}" |
0 commit comments