cargo QoL improvements

Cargo.toml

@@ -1,6 +1,6 @@
 [workspace]
 members = ["src/clippy-tracing", "src/cpu-template-helper", "src/firecracker", "src/jailer", "src/log-instrument", "src/log-instrument-macros", "src/rebase-snap", "src/seccompiler", "src/snapshot-editor"]
-default-members = ["src/firecracker"]
+default-members = ["src/clippy-tracing", "src/cpu-template-helper", "src/firecracker", "src/rebase-snap", "src/seccompiler", "src/snapshot-editor"]
 resolver = "2"
 
 [profile.dev]

src/log-instrument/Cargo.toml

@@ -9,29 +9,23 @@ license = "Apache-2.0"
 [lib]
 bench = false
 
-[[bin]]
+[[example]]
 name = "one"
-bench = false
 
-[[bin]]
+[[example]]
 name = "two"
-bench = false
 
-[[bin]]
+[[example]]
 name = "three"
-bench = false
 
-[[bin]]
+[[example]]
 name = "four"
-bench = false
 
-[[bin]]
+[[example]]
 name = "five"
-bench = false
 
-[[bin]]
+[[example]]
 name = "six"
-bench = false
 
 [dependencies]
 env_logger = "0.10.0"

tests/host_tools/cargo_build.py

@@ -66,15 +66,15 @@ def cargo_test(path, extra_args=""):
 
 
 @with_filelock
-def get_binary(name, *, workspace_dir=FC_WORKSPACE_DIR, example=False):
+def get_binary(name, *, workspace_dir=FC_WORKSPACE_DIR, example=None):
     """Build a binary"""
     target = DEFAULT_BUILD_TARGET
     target_dir = workspace_dir / "build" / "cargo_target"
     bin_path = target_dir / target / "release" / name
     cmd = f"-p {name}"
     if example:
-        bin_path = target_dir / target / "release" / "examples" / name
-        cmd = f"--example {name}"
+        bin_path = target_dir / target / "release" / "examples" / example
+        cmd += f" --example {example}"
     if not bin_path.exists():
         env = {"RUSTFLAGS": get_rustflags()}
         cargo(
@@ -99,9 +99,9 @@ def get_firecracker_binaries(*, workspace_dir=FC_WORKSPACE_DIR):
     )
 
 
-def get_example(name, *args, **kwargs):
+def get_example(name, *args, package="firecracker", **kwargs):
     """Build an example binary"""
-    return get_binary(name, *args, **kwargs, example=True)
+    return get_binary(package, *args, **kwargs, example=name)
 
 
 @with_filelock

tests/integration_tests/functional/test_log_instrument.py

@@ -0,0 +1,89 @@
+# Copyright 2023 Amazon.com, Inc. or its affiliates. All Rights Reserved.
+# SPDX-License-Identifier: Apache-2.0
+
+"""Checks that the output of instrumentation examples is correct"""
+import pytest
+
+from framework import utils
+from host_tools.cargo_build import get_binary
+
+EXPECTED_OUTPUTS = {
+    "one": """[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:29:00Z DEBUG one] cmp: true
+[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:29:00Z INFO  one] 4
+[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:29:00Z DEBUG one] cmp: false
+[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:29:00Z INFO  one] 6
+[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:29:00Z DEBUG one] cmp: false
+[2023-10-12T16:29:00Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:29:00Z INFO  one] 7""".splitlines(),
+    "two": """[2023-10-12T16:29:30Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:29:30Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:29:30Z INFO  two] None
+[2023-10-12T16:29:30Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:29:30Z DEBUG two] [\"a\", \"b\"]
+[2023-10-12T16:29:30Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:29:30Z INFO  two] Some([\"a\", \"b\"])""".splitlines(),
+    "three": """[2023-10-12T16:30:04Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:30:04Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:30:04Z INFO  three] None
+[2023-10-12T16:30:04Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:30:04Z DEBUG three] [\"a\", \"b\"]
+[2023-10-12T16:30:04Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:30:04Z INFO  three] Some([\"a\", \"b\"])""".splitlines(),
+    "four": """[2023-10-12T16:30:37Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:30:37Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:30:37Z INFO  four] None
+[2023-10-12T16:30:37Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:30:37Z DEBUG four] [\"a\", \"b\"]
+[2023-10-12T16:30:37Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:30:37Z INFO  four] Some([\"a\", \"b\"])""".splitlines(),
+    "five": """[2023-10-12T16:31:12Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:31:12Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:31:12Z INFO  five] None
+[2023-10-12T16:31:12Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:31:12Z DEBUG five] [\"a\", \"b\"]
+[2023-10-12T16:31:12Z DEBUG five] 23
+[2023-10-12T16:31:12Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:31:12Z INFO  five] Some([\"a\", \"b\"])""".splitlines(),
+    "six": """[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:31:54Z DEBUG six] cmp: true
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:31:54Z INFO  six] 4
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:31:54Z DEBUG six] cmp: false
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)::one>>two
+[2023-10-12T16:31:54Z DEBUG six] res: 0
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)::one<<two
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:31:54Z INFO  six] 0
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)>>one
+[2023-10-12T16:31:54Z DEBUG six] cmp: false
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)::one>>two
+[2023-10-12T16:31:54Z DEBUG six] res: 1
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)::one<<two
+[2023-10-12T16:31:54Z TRACE log_instrument] ThreadId(1)<<one
+[2023-10-12T16:31:54Z INFO  six] 1""".splitlines(),
+}
+
+
+@pytest.mark.parametrize(
+    "example, expected_output", EXPECTED_OUTPUTS.items(), ids=EXPECTED_OUTPUTS
+)
+def test_instrumentation_example_output(example, expected_output):
+    """Test the output of instrumentation examples does not change"""
+    example_binary = get_binary("log-instrument", example=example)
+
+    # Logging output goes to stderr
+    _, stdout, stderr = utils.run_cmd(str(example_binary))
+
+    assert not stdout
+
+    lines = stderr.splitlines()
+    assert len(lines) == len(expected_output)
+    for line_number, line in enumerate(stderr.splitlines()):
+        # Need to strip off timestamps
+        assert line[20:] == expected_output[line_number][20:]