From d8f98cdcf5405f69592e85793a88910844295694 Mon Sep 17 00:00:00 2001 From: Zhang Tianyang Date: Tue, 30 Jan 2024 19:53:51 +0800 Subject: [PATCH 1/2] log: change log print level Signed-off-by: Zhang Tianyang --- vmm/sandbox/Cargo.lock | 8 ++--- vmm/sandbox/config_clh.toml | 4 ++- vmm/sandbox/src/client.rs | 13 +++++---- vmm/sandbox/src/cloud_hypervisor/mod.rs | 9 +++--- vmm/sandbox/src/network/mod.rs | 5 ++-- vmm/sandbox/src/sandbox.rs | 2 +- vmm/sandbox/src/storage/mod.rs | 5 +++- vmm/sandbox/src/utils.rs | 39 ++++++++++++------------- vmm/task/Cargo.lock | 8 ++--- vmm/task/src/main.rs | 3 +- 10 files changed, 50 insertions(+), 46 deletions(-) diff --git a/vmm/sandbox/Cargo.lock b/vmm/sandbox/Cargo.lock index 5a461b8d..ea87e2f6 100644 --- a/vmm/sandbox/Cargo.lock +++ b/vmm/sandbox/Cargo.lock @@ -426,7 +426,7 @@ dependencies = [ [[package]] name = "containerd-sandbox" version = "0.1.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "anyhow", "async-stream", @@ -454,7 +454,7 @@ dependencies = [ [[package]] name = "containerd-shim" version = "0.3.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "async-trait", "cgroups-rs 0.2.11", @@ -485,7 +485,7 @@ dependencies = [ [[package]] name = "containerd-shim-protos" version = "0.2.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "async-trait", "protobuf 3.2.0", @@ -1561,7 +1561,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "059a34f111a9dee2ce1ac2826a68b24601c4298cfeb1a587c3cb493d5ab46f52" dependencies = [ "libc", - "nix 0.20.0", + "nix 0.26.2", ] [[package]] diff --git a/vmm/sandbox/config_clh.toml b/vmm/sandbox/config_clh.toml index 14d8f960..5e0d3ebc 100644 --- a/vmm/sandbox/config_clh.toml +++ b/vmm/sandbox/config_clh.toml @@ -11,9 +11,11 @@ initrd_path = "" kernel_params = "" hugepages = false entropy_source = "/dev/urandom" -debug = true +debug = false + [hypervisor.task] debug = false + [hypervisor.virtiofsd] path = "/usr/local/bin/virtiofsd" log_level = "info" diff --git a/vmm/sandbox/src/client.rs b/vmm/sandbox/src/client.rs index fb76c67f..e967f536 100644 --- a/vmm/sandbox/src/client.rs +++ b/vmm/sandbox/src/client.rs @@ -253,20 +253,21 @@ pub(crate) async fn client_update_routes( Ok(()) } -pub(crate) async fn client_sync_clock(client: &SandboxServiceClient) { +pub(crate) async fn client_sync_clock(client: &SandboxServiceClient, id: &str) { + let id = id.to_string(); let client = client.clone(); let tolerance_nanos = Duration::from_millis(TIME_DIFF_TOLERANCE_IN_MS).as_nanos() as i64; let clock_id = ClockId::from_raw(nix::libc::CLOCK_REALTIME); tokio::spawn(async move { loop { tokio::time::sleep(Duration::from_secs(TIME_SYNC_PERIOD)).await; - debug!("sync_clock: start sync clock from host to guest"); + debug!("sync_clock {}: start sync clock from host to guest", id); let mut req = SyncClockPacket::new(); match clock_gettime(clock_id) { Ok(ts) => req.ClientSendTime = ts.num_nanoseconds(), Err(e) => { - warn!("failed to get current clock: {}", e); + warn!("sync_clock {}: failed to get current clock: {}", id, e); continue; } } @@ -278,7 +279,7 @@ pub(crate) async fn client_sync_clock(client: &SandboxServiceClient) { match clock_gettime(clock_id) { Ok(ts) => p.ServerArriveTime = ts.num_nanoseconds(), Err(e) => { - warn!("failed to get current clock: {}", e); + warn!("sync_clock {}: failed to get current clock: {}", id, e); continue; } } @@ -290,12 +291,12 @@ pub(crate) async fn client_sync_clock(client: &SandboxServiceClient) { .sync_clock(with_timeout(Duration::from_secs(1).as_nanos() as i64), &p) .await { - error!("sync clock set delta failed: {:?}", e); + error!("sync_clock {}: sync clock set delta failed: {:?}", id, e); } } } Err(e) => { - error!("sync clock get error: {:?}", e); + error!("sync_clock {}: get error: {:?}", id, e); } } } diff --git a/vmm/sandbox/src/cloud_hypervisor/mod.rs b/vmm/sandbox/src/cloud_hypervisor/mod.rs index 00ebff84..70bd2270 100644 --- a/vmm/sandbox/src/cloud_hypervisor/mod.rs +++ b/vmm/sandbox/src/cloud_hypervisor/mod.rs @@ -19,7 +19,7 @@ use std::{os::unix::io::RawFd, process::Stdio}; use anyhow::anyhow; use async_trait::async_trait; use containerd_sandbox::error::{Error, Result}; -use log::{debug, error}; +use log::{debug, error, info}; use serde::{Deserialize, Serialize}; use time::OffsetDateTime; use tokio::{ @@ -137,7 +137,7 @@ impl CloudHypervisorVM { let pid = child .id() .ok_or(anyhow!("the virtiofsd has been polled to completion"))?; - spawn_wait(child, "virtiofsd".to_string(), None, None); + spawn_wait(child, format!("virtiofsd {}", self.id), None, None); Ok(pid) } @@ -150,7 +150,6 @@ impl CloudHypervisorVM { #[async_trait] impl VM for CloudHypervisorVM { async fn start(&mut self) -> Result { - debug!("start vm {}", self.id); create_dir_all(&self.base_dir).await?; let virtiofsd_pid = self.start_virtiofsd().await?; let mut params = self.config.to_cmdline_params("--"); @@ -170,7 +169,7 @@ impl VM for CloudHypervisorVM { set_cmd_netns(&mut cmd, self.netns.to_string())?; cmd.stdout(Stdio::piped()); cmd.stderr(Stdio::piped()); - debug!("start cloud hypervisor with cmdline: {:?}", cmd); + info!("start cloud hypervisor with cmdline: {:?}", cmd); let child = cmd .spawn() .map_err(|e| anyhow!("failed to spawn cloud hypervisor command: {}", e))?; @@ -179,7 +178,7 @@ impl VM for CloudHypervisorVM { let (tx, rx) = tokio::sync::watch::channel((0u32, 0i128)); spawn_wait( child, - "cloud-hypervisor".to_string(), + format!("cloud-hypervisor {}", self.id), Some(pid_file), Some(tx), ); diff --git a/vmm/sandbox/src/network/mod.rs b/vmm/sandbox/src/network/mod.rs index f2f099bb..a34f030b 100644 --- a/vmm/sandbox/src/network/mod.rs +++ b/vmm/sandbox/src/network/mod.rs @@ -19,7 +19,7 @@ use std::{fmt::Debug, os::unix::prelude::AsRawFd, path::Path}; use anyhow::anyhow; use containerd_sandbox::error::Result; use futures_util::TryStreamExt; -use log::{debug, error, warn}; +use log::{debug, error, info, warn}; use nix::{ fcntl::OFlag, sched::{setns, CloneFlags}, @@ -48,8 +48,9 @@ pub struct Network { impl Network { pub async fn new(config: NetworkConfig) -> Result { debug!("create network with config: {:?}", config); + let sandbox_id = config.sandbox_id.to_string(); let network = Self::new_from_netns(config).await?; - debug!("network: {:?}", &network); + info!("network for sandbox {}: {:?}", sandbox_id, &network); Ok(network) } diff --git a/vmm/sandbox/src/sandbox.rs b/vmm/sandbox/src/sandbox.rs index 7905a248..8733fa05 100644 --- a/vmm/sandbox/src/sandbox.rs +++ b/vmm/sandbox/src/sandbox.rs @@ -544,7 +544,7 @@ where pub(crate) async fn sync_clock(&self) { let client_guard = self.client.lock().await; if let Some(client) = &*client_guard { - client_sync_clock(client).await; + client_sync_clock(client, self.id.as_str()).await; } } diff --git a/vmm/sandbox/src/storage/mod.rs b/vmm/sandbox/src/storage/mod.rs index 43748681..c8472535 100644 --- a/vmm/sandbox/src/storage/mod.rs +++ b/vmm/sandbox/src/storage/mod.rs @@ -53,7 +53,10 @@ where } let id = format!("storage{}", self.increment_and_get_id()); - debug!("attach storage for mount {:?} with id {}", m, id); + debug!( + "attach storage to container {} for mount {:?} with id {}", + container_id, m, id + ); if is_block_device(&*m.source).await? { self.handle_block_device(&id, container_id, m).await?; diff --git a/vmm/sandbox/src/utils.rs b/vmm/sandbox/src/utils.rs index e5cb1e91..d527e6f4 100644 --- a/vmm/sandbox/src/utils.rs +++ b/vmm/sandbox/src/utils.rs @@ -30,7 +30,7 @@ use containerd_sandbox::{ data::SandboxData, error::{Error, Result}, }; -use log::{debug, error}; +use log::{error, info}; use nix::{ fcntl::{open, OFlag}, libc::{dup2, fcntl, kill, setns, FD_CLOEXEC, F_GETFD, F_SETFD}, @@ -96,7 +96,6 @@ pub fn get_dns_config(data: &SandboxData) -> Option<&DnsConfig> { data.config.as_ref().and_then(|c| c.dns_config.as_ref()) } -#[allow(dead_code)] pub fn get_total_resources(data: &SandboxData) -> Option { return data .config @@ -114,7 +113,6 @@ pub fn get_total_resources(data: &SandboxData) -> Option Result { let cpuset1_parts = cpuset_parts(cpusets1)?; let cpuset2_parts = cpuset_parts(cpusets2)?; @@ -217,7 +218,6 @@ fn merge_cpusets(cpusets1: &str, cpusets2: &str) -> Result { .join(",")) } -#[allow(dead_code)] fn merge_cpuset(base: (u32, u32), delta: (u32, u32)) -> (u32, u32) { let (mut low, mut high) = base; if delta.1 < low { @@ -235,7 +235,6 @@ fn merge_cpuset(base: (u32, u32), delta: (u32, u32)) -> (u32, u32) { (low, high) } -#[allow(dead_code)] fn cpuset_intersect(cpuset1: (u32, u32), cpuset2: (u32, u32)) -> bool { if cpuset2.1 < cpuset1.0 { return false; @@ -246,7 +245,6 @@ fn cpuset_intersect(cpuset1: (u32, u32), cpuset2: (u32, u32)) -> bool { true } -#[allow(dead_code)] fn cpuset_parts(cpuset: &str) -> Result> { let mut cpuset1_parts = vec![]; let c1 = cpuset.split(','); @@ -256,7 +254,6 @@ fn cpuset_parts(cpuset: &str) -> Result> { Ok(cpuset1_parts) } -#[allow(dead_code)] fn cpuset_one_part(cpuset: &str) -> Result<(u32, u32)> { let parts = cpuset.split('-').collect::>(); let low = parts[0] @@ -273,7 +270,6 @@ fn cpuset_one_part(cpuset: &str) -> Result<(u32, u32)> { Ok((low, high)) } -#[allow(dead_code)] pub fn cpuset_tostring(cpuset: (u32, u32)) -> String { if cpuset.0 == cpuset.1 { return cpuset.0.to_string(); @@ -417,7 +413,7 @@ pub async fn read_std(std: T, prefix: &str) -> Result<()> if c == 0 { return Ok(()); } - debug!("{}: {}", prefix, line.trim()); + info!("{}: {}", prefix, line.trim()); } Err(e) => { error!("failed to read {} log {}", prefix, e); @@ -491,6 +487,7 @@ pub fn init_logger(level: &str) { let log_level = log::LevelFilter::from_str(level).unwrap_or(log::LevelFilter::Info); env_logger::Builder::from_default_env() .format_timestamp_micros() - .filter_level(log_level) + .filter_module("containerd_sandbox", log_level) + .filter_module("vmm_sandboxer", log_level) .init(); } diff --git a/vmm/task/Cargo.lock b/vmm/task/Cargo.lock index 26d1c7cc..48091cd7 100644 --- a/vmm/task/Cargo.lock +++ b/vmm/task/Cargo.lock @@ -198,7 +198,7 @@ dependencies = [ [[package]] name = "containerd-sandbox" version = "0.1.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "anyhow", "async-stream", @@ -226,7 +226,7 @@ dependencies = [ [[package]] name = "containerd-shim" version = "0.3.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "async-trait", "cgroups-rs", @@ -257,7 +257,7 @@ dependencies = [ [[package]] name = "containerd-shim-protos" version = "0.2.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "async-trait", "protobuf 3.2.0", @@ -1532,7 +1532,7 @@ dependencies = [ [[package]] name = "runc" version = "0.2.0" -source = "git+https://github.com/kuasar-io/rust-extensions.git#e915494234c1586902f09f8d322dd2937e916144" +source = "git+https://github.com/kuasar-io/rust-extensions.git#46e401d63850d56f7de02c3f29fb8174bbbb6f4f" dependencies = [ "async-trait", "futures", diff --git a/vmm/task/src/main.rs b/vmm/task/src/main.rs index 3ab6159b..bd0a02fd 100644 --- a/vmm/task/src/main.rs +++ b/vmm/task/src/main.rs @@ -144,7 +144,8 @@ async fn main() { let log_level = LevelFilter::from_str(&config.log_level).unwrap(); env_logger::Builder::from_default_env() .format_timestamp_micros() - .filter_level(log_level) + .filter_module("containerd_shim", log_level) + .filter_module("vmm_task", log_level) .init(); info!("Task server start with config: {:?}", config); match &*config.sharefs_type { From b9ccea8e55dca64c6b8f1c6a17d5efa38910eb57 Mon Sep 17 00:00:00 2001 From: Zhang Tianyang Date: Thu, 1 Feb 2024 12:34:13 +0800 Subject: [PATCH 2/2] script: make `-x` option optional in scripts Signed-off-by: Zhang Tianyang --- Makefile | 6 +++--- vmm/scripts/image/centos/build.sh | 8 ++++---- vmm/scripts/image/centos/build_rootfs.sh | 2 ++ 3 files changed, 9 insertions(+), 7 deletions(-) diff --git a/Makefile b/Makefile index 3449bb41..db556e08 100644 --- a/Makefile +++ b/Makefile @@ -23,15 +23,15 @@ bin/vmm-task: @mkdir -p bin && cp vmm/task/target/${ARCH}-unknown-linux-musl/release/vmm-task bin/vmm-task bin/vmlinux.bin: - @bash -x vmm/scripts/kernel/${HYPERVISOR}/build.sh ${KERNEL_VERSION} + @bash vmm/scripts/kernel/${HYPERVISOR}/build.sh ${KERNEL_VERSION} @mkdir -p bin && cp vmm/scripts/kernel/${HYPERVISOR}/vmlinux.bin bin/vmlinux.bin && rm vmm/scripts/kernel/${HYPERVISOR}/vmlinux.bin bin/kuasar.img: - @bash -x vmm/scripts/image/${GUESTOS_IMAGE}/build.sh image + @bash vmm/scripts/image/${GUESTOS_IMAGE}/build.sh image @mkdir -p bin && cp /tmp/kuasar.img bin/kuasar.img && rm /tmp/kuasar.img bin/kuasar.initrd: - @bash -x vmm/scripts/image/${GUESTOS_IMAGE}/build.sh initrd + @bash vmm/scripts/image/${GUESTOS_IMAGE}/build.sh initrd @mkdir -p bin && cp /tmp/kuasar.initrd bin/kuasar.initrd && rm /tmp/kuasar.initrd bin/wasm-sandboxer: diff --git a/vmm/scripts/image/centos/build.sh b/vmm/scripts/image/centos/build.sh index 9eb86b95..e8bf94c3 100644 --- a/vmm/scripts/image/centos/build.sh +++ b/vmm/scripts/image/centos/build.sh @@ -68,7 +68,7 @@ containerd) --mount type=bind,src="${ROOTFS_DIR}",dst=/tmp/kuasar-rootfs,options=rbind:rw \ ${IMAGE_NAME} \ ${container_name} \ - bash -x /kuasar/vmm/scripts/image/centos/build_rootfs.sh + bash /kuasar/vmm/scripts/image/centos/build_rootfs.sh fn_check_result $? "ctr run ${container_name} return error!" ;; docker) @@ -80,7 +80,7 @@ docker) -v "${REPO_DIR}":/kuasar \ -v "${ROOTFS_DIR}":"/tmp/kuasar-rootfs" \ ${IMAGE_NAME} \ - bash -x /kuasar/vmm/scripts/image/centos/build_rootfs.sh + bash /kuasar/vmm/scripts/image/centos/build_rootfs.sh fn_check_result $? "docker run ${container_name} return error!" ;; isulad) @@ -93,7 +93,7 @@ isulad) -v "${REPO_DIR}":/kuasar \ -v "${ROOTFS_DIR}":"/tmp/kuasar-rootfs" \ ${IMAGE_NAME} \ - bash -x /kuasar/vmm/scripts/image/centos/build_rootfs.sh + bash /kuasar/vmm/scripts/image/centos/build_rootfs.sh fn_check_result $? "isula run ${container_name} return error!" ;; *) @@ -109,7 +109,7 @@ fi case "$1" in image) - bash -x ${REPO_DIR}/vmm/scripts/image/build_image.sh + bash ${REPO_DIR}/vmm/scripts/image/build_image.sh fn_check_result $? "build image failed!" ;; initrd) diff --git a/vmm/scripts/image/centos/build_rootfs.sh b/vmm/scripts/image/centos/build_rootfs.sh index f3da57bb..aaab2455 100644 --- a/vmm/scripts/image/centos/build_rootfs.sh +++ b/vmm/scripts/image/centos/build_rootfs.sh @@ -15,6 +15,8 @@ set -e +[ -n "${DEBUG}" ] && set -x + golang_version="1.20.5" cert_file_path="/kuasar/proxy.crt" ARCH=$(uname -m)