diff --git a/src/dragonball/Cargo.lock b/src/dragonball/Cargo.lock index 3c858bdb5d..c21991b339 100644 --- a/src/dragonball/Cargo.lock +++ b/src/dragonball/Cargo.lock @@ -408,6 +408,17 @@ version = "0.3.8" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "f2696e8a945f658fd14dc3b87242e6b80cd0f36ff04ea560fa39082368847946" +[[package]] +name = "derivative" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fcc3dd5e9e9c0b295d6e1e4d811fb6f157d5ffd784b8d202fc62eac8035a770b" +dependencies = [ + "proc-macro2", + "quote", + "syn 1.0.109", +] + [[package]] name = "digest" version = "0.10.7" @@ -458,6 +469,7 @@ dependencies = [ "dbs-upcall", "dbs-utils", "dbs-virtio-devices", + "derivative", "fuse-backend-rs", "kvm-bindings", "kvm-ioctls", @@ -478,6 +490,7 @@ dependencies = [ "slog-term", "test-utils", "thiserror", + "tracing", "virtio-queue", "vm-memory", "vmm-sys-util", @@ -1255,7 +1268,7 @@ checksum = "a948666b637a0f465e8564c73e89d4dde00d72d4d473cc972f390fc3dcee7d9c" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 2.0.32", ] [[package]] @@ -1609,7 +1622,7 @@ checksum = "4eca7ac642d82aa35b60049a6eccb4be6be75e599bd2e9adb5f875a737654af2" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 2.0.32", ] [[package]] @@ -1740,6 +1753,17 @@ version = "2.5.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "81cdd64d312baedb58e21336b31bc043b77e01cc99033ce76ef539f78e965ebc" +[[package]] +name = "syn" +version = "1.0.109" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "72b64191b275b66ffe2469e8af2c1cfe3bafa67b529ead792a6d0160888b4237" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + [[package]] name = "syn" version = "2.0.32" @@ -1816,7 +1840,7 @@ checksum = "49922ecae66cc8a249b77e68d1d0623c1b2c514f0060c27cdc68bd62a1219d35" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 2.0.32", ] [[package]] @@ -1917,7 +1941,7 @@ checksum = "630bdcf245f78637c13ec01ffae6187cca34625e8c63150d424b59e55af2675e" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 2.0.32", ] [[package]] @@ -1967,9 +1991,21 @@ checksum = "8ce8c33a8d48bd45d624a6e523445fd21ec13d3653cd51f681abf67418f54eb8" dependencies = [ "cfg-if", "pin-project-lite", + "tracing-attributes", "tracing-core", ] +[[package]] +name = "tracing-attributes" +version = "0.1.27" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "34704c8d6ebcbc939824180af020566b01a7c01f80641264eba0999f6c2b6be7" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.32", +] + [[package]] name = "tracing-core" version = "0.1.31" @@ -2122,7 +2158,7 @@ dependencies = [ "once_cell", "proc-macro2", "quote", - "syn", + "syn 2.0.32", "wasm-bindgen-shared", ] @@ -2156,7 +2192,7 @@ checksum = "54681b18a46765f095758388f2d0cf16eb8d4169b639ab575a8f5693af210c7b" dependencies = [ "proc-macro2", "quote", - "syn", + "syn 2.0.32", "wasm-bindgen-backend", "wasm-bindgen-shared", ] diff --git a/src/dragonball/Cargo.toml b/src/dragonball/Cargo.toml index 5ea23a53b6..55cd51e8b8 100644 --- a/src/dragonball/Cargo.toml +++ b/src/dragonball/Cargo.toml @@ -23,6 +23,7 @@ dbs-legacy-devices = { path = "./src/dbs_legacy_devices" } dbs-upcall = { path = "./src/dbs_upcall" , optional = true } dbs-utils = { path = "./src/dbs_utils" } dbs-virtio-devices = { path = "./src/dbs_virtio_devices", optional = true, features = ["virtio-mmio"] } +derivative = "2.2.0" kvm-bindings = "0.6.0" kvm-ioctls = "0.12.0" lazy_static = "1.2" @@ -39,6 +40,7 @@ serde_json = "1.0.9" slog = "2.5.2" slog-scope = "4.4.0" thiserror = "1" +tracing = "0.1.37" vmm-sys-util = "0.11.0" virtio-queue = { version = "0.7.0", optional = true } vm-memory = { version = "0.10.0", features = ["backend-mmap"] } diff --git a/src/dragonball/src/api/v1/vmm_action.rs b/src/dragonball/src/api/v1/vmm_action.rs index f8914f10d9..6aa9000ecd 100644 --- a/src/dragonball/src/api/v1/vmm_action.rs +++ b/src/dragonball/src/api/v1/vmm_action.rs @@ -7,12 +7,15 @@ // found in the THIRD-PARTY file. use std::fs::File; +use std::sync::{Arc, Mutex}; use crossbeam_channel::{Receiver, Sender, TryRecvError}; use log::{debug, error, info, warn}; +use tracing::instrument; use crate::error::{Result, StartMicroVmError, StopMicrovmError}; use crate::event_manager::EventManager; +use crate::tracer::{DragonballTracer, TraceError, TraceInfo}; use crate::vm::{CpuTopology, KernelConfigInfo, VmConfigInfo}; use crate::vmm::Vmm; @@ -121,6 +124,12 @@ pub enum VmmActionError { /// Balloon device related errors. #[error("virtio-balloon device error: {0}")] Balloon(#[source] BalloonDeviceError), + /// Setup tracing Failed. + #[error("Setup tracing failed: {0}")] + SetupTracingFailed(#[source] TraceError), + /// End tracing Failed. + #[error("End tracing failed: {0}")] + EndTracingFailed(#[source] TraceError), } /// This enum represents the public interface of the VMM. Each action contains various @@ -148,6 +157,10 @@ pub enum VmmAction { /// Set the microVM configuration (memory & vcpu) using `VmConfig` as input. This /// action can only be called before the microVM has booted. SetVmConfiguration(VmConfigInfo), + /// Set the VMM tracing. + SetHypervisorTracing(TraceInfo), + /// End VMM tracing. + EndHypervisorTracing, #[cfg(feature = "virtio-vsock")] /// Add a new vsock device or update one that already exists using the @@ -239,6 +252,7 @@ pub struct VmmService { from_api: Receiver, to_api: Sender, machine_config: VmConfigInfo, + tracer: Arc>, } impl VmmService { @@ -248,6 +262,7 @@ impl VmmService { from_api, to_api, machine_config: VmConfigInfo::default(), + tracer: Arc::new(Mutex::new(DragonballTracer::new())), } } @@ -278,6 +293,8 @@ impl VmmService { VmmAction::SetVmConfiguration(machine_config) => { self.set_vm_configuration(vmm, machine_config) } + VmmAction::SetHypervisorTracing(trace_info) => self.setup_tracing(trace_info), + VmmAction::EndHypervisorTracing => self.end_tracing(), #[cfg(feature = "virtio-vsock")] VmmAction::InsertVsockDevice(vsock_cfg) => self.add_vsock_device(vmm, vsock_cfg), #[cfg(feature = "virtio-blk")] @@ -334,6 +351,7 @@ impl VmmService { Ok(()) } + #[instrument(skip(self))] fn configure_boot_source( &self, vmm: &mut Vmm, @@ -373,6 +391,7 @@ impl VmmService { Ok(VmmData::Empty) } + #[instrument(skip(self, event_mgr))] fn start_microvm(&mut self, vmm: &mut Vmm, event_mgr: &mut EventManager) -> VmmRequestResult { use self::StartMicroVmError::MicroVMAlreadyRunning; use self::VmmActionError::StartMicroVm; @@ -389,6 +408,7 @@ impl VmmService { .map_err(StartMicroVm) } + #[instrument(skip(self))] fn shutdown_microvm(&mut self, vmm: &mut Vmm) -> VmmRequestResult { vmm.event_ctx.exit_evt_triggered = true; @@ -396,6 +416,7 @@ impl VmmService { } /// Get prometheus metrics. + #[instrument(skip(self))] fn get_hypervisor_metrics(&self) -> VmmRequestResult { get_hypervisor_metrics() .map_err(|_| VmmActionError::GetHypervisorMetrics) @@ -403,6 +424,7 @@ impl VmmService { } /// Set virtual machine configuration. + #[instrument(skip(self))] pub fn set_vm_configuration( &mut self, vmm: &mut Vmm, @@ -488,7 +510,32 @@ impl VmmService { Ok(VmmData::Empty) } + /// Setup dragonball tracing. + fn setup_tracing(&self, trace_info: TraceInfo) -> VmmRequestResult { + let mut tracer = self.tracer.lock().unwrap(); + tracer + .setup_tracing(trace_info) + .map(|_| VmmData::Empty) + .map_err(VmmActionError::SetupTracingFailed) + } + + /// Get dragonball tracer. + pub fn tracer(&self) -> Arc> { + self.tracer.clone() + } + + /// end dragonball tracing. + #[instrument(skip(self))] + fn end_tracing(&self) -> VmmRequestResult { + let mut tracer = self.tracer.lock().unwrap(); + tracer + .end_tracing() + .map(|_| VmmData::Empty) + .map_err(VmmActionError::EndTracingFailed) + } + #[cfg(feature = "virtio-vsock")] + #[instrument(skip(self))] fn add_vsock_device(&self, vmm: &mut Vmm, config: VsockDeviceConfigInfo) -> VmmRequestResult { let vm = vmm.get_vm_mut().ok_or(VmmActionError::InvalidVMID)?; if vm.is_vm_initialized() { @@ -523,6 +570,7 @@ impl VmmService { #[cfg(feature = "virtio-blk")] // Only call this function as part of the API. // If the drive_id does not exist, a new Block Device Config is added to the list. + #[instrument(skip(self, event_mgr))] fn add_block_device( &mut self, vmm: &mut Vmm, @@ -548,6 +596,7 @@ impl VmmService { #[cfg(feature = "virtio-blk")] /// Updates configuration for an emulated net device as described in `config`. + #[instrument(skip(self))] fn update_blk_rate_limiters( &mut self, vmm: &mut Vmm, @@ -564,6 +613,7 @@ impl VmmService { #[cfg(feature = "virtio-blk")] // Remove the device + #[instrument(skip(self, event_mgr))] fn remove_block_device( &mut self, vmm: &mut Vmm, @@ -583,6 +633,7 @@ impl VmmService { } #[cfg(feature = "virtio-net")] + #[instrument(skip(self, event_mgr))] fn add_virtio_net_device( &mut self, vmm: &mut Vmm, @@ -610,6 +661,7 @@ impl VmmService { } #[cfg(feature = "virtio-net")] + #[instrument(skip(self))] fn update_net_rate_limiters( &mut self, vmm: &mut Vmm, @@ -625,6 +677,7 @@ impl VmmService { } #[cfg(feature = "virtio-fs")] + #[instrument(skip(self))] fn add_fs_device(&mut self, vmm: &mut Vmm, config: FsDeviceConfigInfo) -> VmmRequestResult { let vm = vmm.get_vm_mut().ok_or(VmmActionError::InvalidVMID)?; let hotplug = vm.is_vm_initialized(); @@ -644,6 +697,7 @@ impl VmmService { } #[cfg(feature = "virtio-fs")] + #[instrument(skip(self))] fn manipulate_fs_backend_fs( &self, vmm: &mut Vmm, @@ -661,6 +715,7 @@ impl VmmService { } #[cfg(feature = "virtio-fs")] + #[instrument(skip(self))] fn update_fs_rate_limiters( &self, vmm: &mut Vmm, @@ -678,6 +733,7 @@ impl VmmService { } #[cfg(feature = "hotplug")] + #[instrument(skip(self))] fn resize_vcpu(&mut self, vmm: &mut Vmm, config: VcpuResizeInfo) -> VmmRequestResult { if !cfg!(feature = "dbs-upcall") { warn!("We only support cpu resize through upcall server in the guest kernel now, please enable dbs-upcall feature."); @@ -704,6 +760,7 @@ impl VmmService { } #[cfg(feature = "virtio-mem")] + #[instrument(skip(self, event_mgr))] fn add_mem_device( &mut self, vmm: &mut Vmm, @@ -730,6 +787,7 @@ impl VmmService { } #[cfg(feature = "virtio-balloon")] + #[instrument(skip(self, event_mgr))] fn add_balloon_device( &mut self, vmm: &mut Vmm, diff --git a/src/dragonball/src/event_manager.rs b/src/dragonball/src/event_manager.rs index 69bf4dab4c..a13415f57d 100644 --- a/src/dragonball/src/event_manager.rs +++ b/src/dragonball/src/event_manager.rs @@ -25,6 +25,7 @@ pub(crate) const EPOLL_EVENT_EXIT: u32 = 0; pub(crate) const EPOLL_EVENT_API_REQUEST: u32 = 1; /// Shared information between vmm::vmm_thread_event_loop() and VmmEpollHandler. +#[derive(Debug)] pub(crate) struct EventContext { pub api_event_fd: EventFd, pub api_event_triggered: bool, diff --git a/src/dragonball/src/lib.rs b/src/dragonball/src/lib.rs index 26142a4562..e201ee2963 100644 --- a/src/dragonball/src/lib.rs +++ b/src/dragonball/src/lib.rs @@ -32,6 +32,8 @@ pub mod metric; pub mod resource_manager; /// Signal handler for virtual machines. pub mod signal_handler; +/// Dragonball Tracer. +pub mod tracer; /// Virtual CPU manager for virtual machines. pub mod vcpu; /// Virtual machine manager for virtual machines. diff --git a/src/dragonball/src/tracer.rs b/src/dragonball/src/tracer.rs new file mode 100644 index 0000000000..f7e826c051 --- /dev/null +++ b/src/dragonball/src/tracer.rs @@ -0,0 +1,102 @@ +// Copyright (C) 2023 Alibaba Cloud. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 + +use std::sync::Arc; + +use anyhow::Result; +use derivative::Derivative; +use log::{info, warn}; +use tracing::subscriber::DefaultGuard; +use tracing::{span::EnteredSpan, subscriber::NoSubscriber, trace_span, Subscriber}; + +/// Error for dragonball tracer. +#[derive(Debug, thiserror::Error)] +pub enum TraceError { + /// Tracing is already enabled. + #[error("Tracing is already enabled.")] + AlreadyEnabled, +} + +/// Configuration information for tracing feature. +#[derive(Clone, Derivative)] +#[derivative(Debug, PartialEq, Eq)] +pub struct TraceInfo { + /// Sandbox id. + pub sid: String, + /// subscriber from runtime. + #[derivative(Debug = "ignore", PartialEq = "ignore")] + pub subscriber: Arc, +} + +/// drabonball tracer. +/// +/// The tracer wrapper for dragonball. To enable tracing feature, you need to call +/// [`setup_tracing`] first. +pub struct DragonballTracer { + /// Dragonball tracing subscriber. + subscriber: Arc, + /// Subscriber guard. The lifetime is as same as tracer. + sub_guard: Option, + /// Tracing enabled flag. + enabled: bool, + /// Dragonball tracing root span. + root_span: Option, +} + +/// The fields should always be private and the methods should be exposed in a safe. +unsafe impl Send for DragonballTracer {} + +impl Default for DragonballTracer { + fn default() -> Self { + Self::new() + } +} + +impl DragonballTracer { + /// Create a dragonball tracer instance. + pub fn new() -> Self { + Self { + subscriber: Arc::new(NoSubscriber::default()), + sub_guard: None, + enabled: false, + root_span: None, + } + } + + /// Return whether the tracing is enabled, enabled by [`setup_tracing`] + pub fn enabled(&self) -> bool { + self.enabled + } + + /// setup tracing feature. + pub fn setup_tracing(&mut self, config: TraceInfo) -> Result<(), TraceError> { + if self.enabled { + warn!("Tracing is already enabled"); + return Err(TraceError::AlreadyEnabled); + } + self.enabled = true; + self.subscriber = config.subscriber; + + // set the default subscriber for the current thread + self.sub_guard = Some(tracing::subscriber::set_default(self.subscriber.clone())); + self.root_span = Some(trace_span!("dragonball-root").entered()); + info!("Enable tracing successfully"); + Ok(()) + } + + /// end tracing for application. + pub fn end_tracing(&mut self) -> Result<(), TraceError> { + if self.enabled { + // root span must drop before the default subscriber guard is dropped. + if let Some(span) = self.root_span.take() { + span.exit(); + } + if let Some(guard) = self.sub_guard.take() { + drop(guard); + } + self.enabled = false; + info!("Ending tracing successfully"); + } + Ok(()) + } +} diff --git a/src/dragonball/src/vmm.rs b/src/dragonball/src/vmm.rs index 72c799e111..b84b15682c 100644 --- a/src/dragonball/src/vmm.rs +++ b/src/dragonball/src/vmm.rs @@ -6,12 +6,14 @@ // Use of this source code is governed by a BSD-style license that can be // found in the THIRD-PARTY file. +use std::fmt::Formatter; use std::os::unix::io::RawFd; use std::sync::{Arc, Mutex, RwLock}; use dbs_utils::epoll_manager::EpollManager; use log::{error, info, warn}; use seccompiler::BpfProgram; +use tracing::instrument; use vmm_sys_util::eventfd::EventFd; use crate::api::v1::{InstanceInfo, VmmService}; @@ -137,7 +139,11 @@ impl Vmm { } if v.event_ctx.exit_evt_triggered { info!("Gracefully terminated VMM control loop"); - return v.stop(EXIT_CODE_OK as i32); + let ret = v.stop(EXIT_CODE_OK as i32); + let tracer = service.tracer(); + let mut tracer_guard = tracer.lock().unwrap(); + tracer_guard.end_tracing().expect("End tracing err"); + return ret; } } Err(e) => { @@ -154,6 +160,7 @@ impl Vmm { } /// Waits for all vCPUs to exit and terminates the Dragonball process. + #[instrument(name = "stop vmm")] fn stop(&mut self, exit_code: i32) -> i32 { info!("Vmm is stopping."); if let Some(vm) = self.get_vm_mut() { @@ -194,6 +201,17 @@ impl Vmm { } } +impl std::fmt::Debug for Vmm { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + f.debug_struct("Vmm") + .field("event_ctx", &self.event_ctx) + .field("vm", &self.vm.shared_info()) + .field("vcpu_seccomp_filter", &self.vcpu_seccomp_filter) + .field("vmm_seccomp_filter", &self.vmm_seccomp_filter) + .finish() + } +} + #[cfg(test)] pub(crate) mod tests { use test_utils::skip_if_not_root;