Skip to content

Commit

Permalink
fix: move the logging message where it's effective
Browse files Browse the repository at this point in the history 
Move the message after the logger has been configured, so it actually
gets printed.

Eliminate redundant message that outputs internal vmm crate version
0.1.0.

Fixes: 96ed457, 332f218

Signed-off-by: Pablo Barbáchano <pablob@amazon.com>
  • Loading branch information
@pb8o
pb8o committed Oct 18, 2023
1 parent e71046f commit 78c26af
Show file tree
Hide file tree
Showing 4 changed files with 52 additions and 100 deletions.
52 changes: 26 additions & 26 deletions src/firecracker/src/main.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -263,6 +263,32 @@ fn main_exec() -> Result<(), MainError> {
return Ok(());
}

// It's safe to unwrap here because the field's been provided with a default value.
let instance_id = arguments.single_value("id").unwrap();
validate_instance_id(instance_id.as_str()).expect("Invalid instance ID");

// Apply the logger configuration.
vmm::logger::INSTANCE_ID
.set(String::from(instance_id))
.unwrap();
let log_path = arguments.single_value("log-path").map(PathBuf::from);
let level = arguments
.single_value("level")
.map(|s| vmm::logger::LevelFilter::from_str(s))
.transpose()
.map_err(MainError::InvalidLogLevel)?;
let show_level = arguments.flag_present("show-level").then_some(true);
let show_log_origin = arguments.flag_present("show-level").then_some(true);
LOGGER
.update(LoggerConfig {
log_path,
level,
show_level,
show_log_origin,
})
.map_err(MainError::LoggerInitialization)?;
info!("Running Firecracker v{FIRECRACKER_VERSION}");

register_signal_handlers().map_err(MainError::RegisterSignalHandlers)?;

#[cfg(target_arch = "aarch64")]
Expand All @@ -286,39 +312,13 @@ fn main_exec() -> Result<(), MainError> {
// deprecating one.
// warn_deprecated_parameters(&arguments);

// It's safe to unwrap here because the field's been provided with a default value.
let instance_id = arguments.single_value("id").unwrap();
validate_instance_id(instance_id.as_str()).expect("Invalid instance ID");

let instance_info = InstanceInfo {
id: instance_id.clone(),
state: VmState::NotStarted,
vmm_version: FIRECRACKER_VERSION.to_string(),
app_name: "Firecracker".to_string(),
};

let id = arguments.single_value("id").map(|s| s.as_str()).unwrap();
vmm::logger::INSTANCE_ID.set(String::from(id)).unwrap();
info!("Running Firecracker v{FIRECRACKER_VERSION}");

// Apply the logger configuration.
let log_path = arguments.single_value("log-path").map(PathBuf::from);
let level = arguments
.single_value("level")
.map(|s| vmm::logger::LevelFilter::from_str(s))
.transpose()
.map_err(MainError::InvalidLogLevel)?;
let show_level = arguments.flag_present("show-level").then_some(true);
let show_log_origin = arguments.flag_present("show-level").then_some(true);
LOGGER
.update(LoggerConfig {
log_path,
level,
show_level,
show_log_origin,
})
.map_err(MainError::LoggerInitialization)?;

if let Some(metrics_path) = arguments.single_value("metrics-path") {
let metrics_config = MetricsConfig {
metrics_path: PathBuf::from(metrics_path),
Expand Down
12 changes: 1 addition & 11 deletions src/vmm/src/logger/logging.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,8 +22,6 @@ pub const DEFAULT_LEVEL: log::LevelFilter = log::LevelFilter::Info;
pub const DEFAULT_INSTANCE_ID: &str = "anonymous-instance";
/// Instance id.
pub static INSTANCE_ID: OnceLock<String> = OnceLock::new();
/// Semver version of Firecracker.
const FIRECRACKER_VERSION: &str = env!("CARGO_PKG_VERSION");

/// The logger.
///
Expand Down Expand Up @@ -62,7 +60,7 @@ impl Logger {
.unwrap_or(DEFAULT_LEVEL),
);

let target_changed = if let Some(log_path) = config.log_path {
if let Some(log_path) = config.log_path {
let file = std::fs::OpenOptions::new()
.custom_flags(libc::O_NONBLOCK)
.read(true)
Expand All @@ -71,9 +69,6 @@ impl Logger {
.map_err(LoggerUpdateError)?;

guard.target = Some(file);
true
} else {
false
};

if let Some(show_level) = config.show_level {
Expand All @@ -87,11 +82,6 @@ impl Logger {
// Ensure we drop the guard before attempting to log, otherwise this
// would deadlock.
drop(guard);
if target_changed {
// We log this when a target is changed so it is always the 1st line logged, this
// maintains some previous behavior to minimize a breaking change.
log::info!("Running Firecracker v{FIRECRACKER_VERSION}");
}

Ok(())
}
Expand Down
12 changes: 9 additions & 3 deletions tests/framework/microvm.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -450,6 +450,8 @@ def spawn(
self,
log_file="fc.log",
log_level="Debug",
log_show_level=False,
log_show_origin=False,
metrics_path="fc.ndjson",
):
"""Start a microVM as a daemon or in a screen session."""
Expand All @@ -461,10 +463,14 @@ def spawn(
self.log_file = Path(self.path) / log_file
self.log_file.touch()
self.create_jailed_resource(self.log_file)
# The default value for `level`, when configuring the
# logger via cmd line, is `Warning`. We set the level
# to `Debug` to also have the boot time printed in fifo.
# The default value for `level`, when configuring the logger via cmd
# line, is `Info`. We set the level to `Debug` to also have the boot
# time printed in the log.
self.jailer.extra_args.update({"log-path": log_file, "level": log_level})
if log_show_level:
self.jailer.extra_args["show-level"] = None
if log_show_origin:
self.jailer.extra_args["show-log-origin"] = None

if metrics_path is not None:
self.metrics_file = Path(self.path) / metrics_path
Expand Down
76 changes: 16 additions & 60 deletions tests/integration_tests/functional/test_logging.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
"""Tests the format of human readable logs.
It checks the response of the API configuration calls and the logs that show
up in the configured logging FIFO.
up in the configured logging file.
"""

import re
Expand Down Expand Up @@ -71,48 +71,6 @@ def check_log_message_format(log_str, instance_id, level, show_level, show_origi
assert tag_level_no <= configured_level_no


def test_no_origin_logs(test_microvm_with_api):
"""
Check that logs do not contain the origin (i.e file and line number).
"""
_test_log_config(microvm=test_microvm_with_api, show_level=True, show_origin=False)


def test_no_level_logs(test_microvm_with_api):
"""
Check that logs do not contain the level.
"""
_test_log_config(microvm=test_microvm_with_api, show_level=False, show_origin=True)


def test_no_nada_logs(test_microvm_with_api):
"""
Check that logs do not contain either level or origin.
"""
_test_log_config(microvm=test_microvm_with_api, show_level=False, show_origin=False)


def test_info_logs(test_microvm_with_api):
"""
Check output of logs when minimum level to be displayed is info.
"""
_test_log_config(microvm=test_microvm_with_api)


def test_warn_logs(test_microvm_with_api):
"""
Check output of logs when minimum level to be displayed is warning.
"""
_test_log_config(microvm=test_microvm_with_api, log_level="Warning")


def test_error_logs(test_microvm_with_api):
"""
Check output of logs when minimum level of logs displayed is error.
"""
_test_log_config(microvm=test_microvm_with_api, log_level="Error")


def test_log_config_failure(test_microvm_with_api):
"""
Check passing invalid FIFOs is detected and reported as an error.
Expand Down Expand Up @@ -212,27 +170,25 @@ def test_api_requests_logs(test_microvm_with_api):
)


# pylint: disable=W0102
def _test_log_config(microvm, log_level="Info", show_level=True, show_origin=True):
@pytest.mark.parametrize(
"log_level,show_level,show_origin",
[
("Info", True, True),
("Info", False, True),
("Info", True, False),
("Info", False, False),
("Error", False, False),
("Warning", False, False),
],
)
def test_log_config(uvm_plain, log_level, show_level, show_origin):
"""Exercises different scenarios for testing the logging config."""
microvm.spawn(log_file=None)
# only works if log level is Debug
microvm.time_api_requests = False

# Configure logging.
log_path = Path(microvm.path) / "log"
log_path.touch()
microvm.api.logger.put(
log_path=microvm.create_jailed_resource(log_path),
level=log_level,
show_level=show_level,
show_log_origin=show_origin,
microvm = uvm_plain
microvm.spawn(
log_level=log_level, log_show_level=show_level, log_show_origin=show_origin
)
microvm.log_file = log_path

microvm.basic_config()
microvm.start()

lines = microvm.log_data.splitlines()

# Check for `Running Firecracker` message.
Expand Down

0 comments on commit 78c26af

Please sign in to comment.