diff --git a/.github/actions/spelling/expect.txt b/.github/actions/spelling/expect.txt index ea183bb5..a04c71c9 100644 --- a/.github/actions/spelling/expect.txt +++ b/.github/actions/spelling/expect.txt @@ -3,6 +3,7 @@ AAFFBB aarch abe addrpair +advapi almalinux ATL ATLMFC @@ -88,7 +89,9 @@ etest etestoutputs etestsharedstorage EToken +etw EUID +EVENTLOG evt exampledatadiskname exampleosdiskname @@ -325,6 +328,7 @@ wdk wdksetup Werror westus +wevtapi WFP winapi windowsazureguestagent diff --git a/Cargo.lock b/Cargo.lock index 982d70ac..a72dcfb3 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -63,6 +63,21 @@ version = "0.2.18" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5c6cb57a04249c6480766f7f7cef5467412af1490f8d1e243141daddada3264f" +[[package]] +name = "android-tzdata" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e999941b234f3131b00bc13c22d06e8c5ff726d1b6318ac7eb276997bbb4fef0" + +[[package]] +name = "android_system_properties" +version = "0.1.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "819e7219dbd41043ac279b19830f2efc897156490d7fd6ea916720117ee66311" +dependencies = [ + "libc", +] + [[package]] name = "anstream" version = "0.6.15" @@ -217,6 +232,12 @@ version = "2.6.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b048fb63fd8b5923fc5aa7b340d8e156aec7ec02f0c78fa8a6ddc2613f6f71de" +[[package]] +name = "bumpalo" +version = "3.18.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "793db76d6187cd04dff33004d8e6c9cc4e05cd330500379d2394209271b4aeee" + [[package]] name = "byteorder" version = "1.5.0" @@ -229,6 +250,15 @@ version = "1.7.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "8318a53db07bb3f8dca91a600466bdb3f2eaadeedfdbcf02e1accbad9271ba50" +[[package]] +name = "cc" +version = "1.2.27" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d487aa071b5f64da6f19a3e848e3578944b726ee5a4854b82172f02aa876bfdc" +dependencies = [ + "shlex", +] + [[package]] name = "cfg-if" version = "1.0.0" @@ -241,6 +271,20 @@ version = "0.2.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "613afe47fcd5fac7ccf1db93babcb082c5994d996f20b8b159f2ad1658eb5724" +[[package]] +name = "chrono" +version = "0.4.41" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c469d952047f47f91b68d1cba3f10d63c11d73e4636f24f08daf0278abf01c4d" +dependencies = [ + "android-tzdata", + "iana-time-zone", + "js-sys", + "num-traits", + "wasm-bindgen", + "windows-link", +] + [[package]] name = "clap" version = "4.5.18" @@ -594,6 +638,30 @@ dependencies = [ "tokio", ] +[[package]] +name = "iana-time-zone" +version = "0.1.63" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b0c919e5debc312ad217002b8048a17b7d83f80703865bbfcfebb0458b0b27d8" +dependencies = [ + "android_system_properties", + "core-foundation-sys", + "iana-time-zone-haiku", + "js-sys", + "log", + "wasm-bindgen", + "windows-core 0.61.2", +] + +[[package]] +name = "iana-time-zone-haiku" +version = "0.1.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f31827a206f56af32e590ba56d5d2d085f558508192593743f16b2306495269f" +dependencies = [ + "cc", +] + [[package]] name = "indexmap" version = "2.7.1" @@ -625,6 +693,16 @@ version = "1.0.11" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49f1f14873335454500d59611f1cf4a4b0f786f9ac11f4312a78e4cf2566695b" +[[package]] +name = "js-sys" +version = "0.3.77" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1cfaf33c695fc6e08064efbc1f72ec937429614f25eef83af942d0e227c3a28f" +dependencies = [ + "once_cell", + "wasm-bindgen", +] + [[package]] name = "libc" version = "0.2.171" @@ -802,6 +880,7 @@ name = "proxy_agent_shared" version = "9.9.9" dependencies = [ "backtrace", + "chrono", "concurrent-queue", "ctor", "log", @@ -809,6 +888,7 @@ dependencies = [ "os_info", "regex", "serde", + "serde-xml-rs", "serde_derive", "serde_json", "thiserror", @@ -923,6 +1003,12 @@ dependencies = [ "semver", ] +[[package]] +name = "rustversion" +version = "1.0.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8a0d197bd2c9dc6e53b84da9556a69ba4cdfab8619eb41a8bd1cc2027a0f6b1d" + [[package]] name = "ryu" version = "1.0.18" @@ -946,9 +1032,9 @@ dependencies = [ [[package]] name = "serde-xml-rs" -version = "0.6.0" +version = "0.8.1" source = "registry+https://github.com/rust-lang/crates.io-index" -checksum = "fb3aa78ecda1ebc9ec9847d5d3aba7d618823446a049ba2491940506da6e2782" +checksum = "53630160a98edebde0123eb4dfd0fce6adff091b2305db3154a9e920206eb510" dependencies = [ "log", "serde", @@ -979,6 +1065,12 @@ dependencies = [ "serde", ] +[[package]] +name = "shlex" +version = "1.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0fda2ff0d084019ba4d7c6f371c95d8fd75ce3524c3cb8fb653a3023f6323e64" + [[package]] name = "slab" version = "0.4.9" @@ -1295,6 +1387,64 @@ version = "0.11.0+wasi-snapshot-preview1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9c8d87e72b64a3b4db28d11ce29237c246188f4f51057d65a7eab63b7987e423" +[[package]] +name = "wasm-bindgen" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1edc8929d7499fc4e8f0be2262a241556cfc54a0bea223790e71446f2aab1ef5" +dependencies = [ + "cfg-if", + "once_cell", + "rustversion", + "wasm-bindgen-macro", +] + +[[package]] +name = "wasm-bindgen-backend" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2f0a0651a5c2bc21487bde11ee802ccaf4c51935d0d3d42a6101f98161700bc6" +dependencies = [ + "bumpalo", + "log", + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-macro" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7fe63fc6d09ed3792bd0897b314f53de8e16568c2b3f7982f468c0bf9bd0b407" +dependencies = [ + "quote", + "wasm-bindgen-macro-support", +] + +[[package]] +name = "wasm-bindgen-macro-support" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8ae87ea40c9f689fc23f209965b6fb8a99ad69aeeb0231408be24920604395de" +dependencies = [ + "proc-macro2", + "quote", + "syn", + "wasm-bindgen-backend", + "wasm-bindgen-shared", +] + +[[package]] +name = "wasm-bindgen-shared" +version = "0.2.100" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1a05d73b933a847d6cccdda8f838a22ff101ad9bf93e33684f39c1f5f0eece3d" +dependencies = [ + "unicode-ident", +] + [[package]] name = "widestring" version = "0.4.3" @@ -1335,7 +1485,7 @@ version = "0.52.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "e48a53791691ab099e5e2ad123536d0fff50652600abaf43bbf952894110d0be" dependencies = [ - "windows-core", + "windows-core 0.52.0", "windows-targets", ] @@ -1360,6 +1510,56 @@ dependencies = [ "windows-targets", ] +[[package]] +name = "windows-core" +version = "0.61.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c0fdd3ddb90610c7638aa2b3a3ab2904fb9e5cdbecc643ddb3647212781c4ae3" +dependencies = [ + "windows-implement", + "windows-interface", + "windows-link", + "windows-result", + "windows-strings", +] + +[[package]] +name = "windows-implement" +version = "0.60.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a47fddd13af08290e67f4acabf4b459f647552718f683a7b415d290ac744a836" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "windows-interface" +version = "0.59.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bd9211b69f8dcdfa817bfd14bf1c97c9188afa36f4750130fcdf3f400eca9fa8" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + +[[package]] +name = "windows-link" +version = "0.1.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5e6ad25900d524eaabdbbb96d20b4311e1e7ae1699af4fb28c17ae66c80d798a" + +[[package]] +name = "windows-result" +version = "0.3.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "56f42bd332cc6c8eac5af113fc0c1fd6a8fd2aa08a0119358686e5160d0586c6" +dependencies = [ + "windows-link", +] + [[package]] name = "windows-service" version = "0.7.0" @@ -1371,6 +1571,15 @@ dependencies = [ "windows-sys", ] +[[package]] +name = "windows-strings" +version = "0.4.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "56e6c93f3a0c3b36176cb1327a4958a0353d5d166c2a35cb268ace15e91d3b57" +dependencies = [ + "windows-link", +] + [[package]] name = "windows-sys" version = "0.52.0" diff --git a/proxy_agent/Cargo.toml b/proxy_agent/Cargo.toml index f16a52c3..c5b14598 100644 --- a/proxy_agent/Cargo.toml +++ b/proxy_agent/Cargo.toml @@ -12,7 +12,7 @@ once_cell = "1.17.0" # use Lazy serde = "1.0.152" serde_derive = "1.0.152" serde_json = "1.0.91" # json Deserializer -serde-xml-rs = "0.6.0" # xml Deserializer +serde-xml-rs = "0.8.1" # xml Deserializer with xml attribute bitflags = "2.6.0" # support bitflag enum hmac-sha256 = "1.1.6" # use HMAC using the SHA-256 hash function hex = "0.4.3" # hex encode diff --git a/proxy_agent/config/GuestProxyAgent.linux.json b/proxy_agent/config/GuestProxyAgent.linux.json index 03288fc3..34007661 100644 --- a/proxy_agent/config/GuestProxyAgent.linux.json +++ b/proxy_agent/config/GuestProxyAgent.linux.json @@ -8,5 +8,6 @@ "ebpfProgramName": "ebpf_cgroup.o", "cgroupRoot": "/sys/fs/cgroup", "fileLogLevel": "Trace", - "fileLogLevelForEvents": "Info" + "fileLogLevelForEvents": "Info", + "fileLogLevelForSystemEvents": "Info" } \ No newline at end of file diff --git a/proxy_agent/config/GuestProxyAgent.windows.json b/proxy_agent/config/GuestProxyAgent.windows.json index db05cdda..ccad256c 100644 --- a/proxy_agent/config/GuestProxyAgent.windows.json +++ b/proxy_agent/config/GuestProxyAgent.windows.json @@ -7,5 +7,6 @@ "hostGAPluginSupport": 1, "ebpfProgramName": "redirect.bpf.sys", "fileLogLevel": "Trace", - "fileLogLevelForEvents": "Info" + "fileLogLevelForEvents": "Info", + "fileLogLevelForSystemEvents": "Info" } \ No newline at end of file diff --git a/proxy_agent/src/common/config.rs b/proxy_agent/src/common/config.rs index dc8d6374..cf2df59b 100644 --- a/proxy_agent/src/common/config.rs +++ b/proxy_agent/src/common/config.rs @@ -74,6 +74,10 @@ pub fn get_file_log_level_for_events() -> Option { SYSTEM_CONFIG.get_file_log_level_for_events() } +pub fn get_file_log_level_for_system_events() -> Option { + SYSTEM_CONFIG.get_file_log_level_for_system_events() +} + #[derive(Serialize, Deserialize)] #[allow(non_snake_case)] pub struct Config { @@ -95,6 +99,8 @@ pub struct Config { cgroupRoot: Option, #[serde(skip_serializing_if = "Option::is_none")] fileLogLevelForEvents: Option, + #[serde(skip_serializing_if = "Option::is_none")] + fileLogLevelForSystemEvents: Option, } impl Default for Config { @@ -193,6 +199,14 @@ impl Config { } None } + + pub fn get_file_log_level_for_system_events(&self) -> Option { + if let Some(file_log_level) = &self.fileLogLevelForSystemEvents { + let log_level = LoggerLevel::from_str(file_log_level).unwrap_or(LoggerLevel::Info); + return Some(log_level); + } + None + } } #[cfg(test)] @@ -280,6 +294,12 @@ mod tests { "get_file_log_level_for_events mismatch" ); + assert_eq!( + proxy_agent_shared::logger::LoggerLevel::Info, + config.get_file_log_level_for_system_events().unwrap(), + "get_file_log_level_for_system_events mismatch" + ); + // clean up _ = fs::remove_dir_all(&temp_test_path); } @@ -296,7 +316,8 @@ mod tests { "hostGAPluginSupport": 1, "imdsSupport": 1, "ebpfProgramName": "ebpfProgramName", - "fileLogLevelForEvents": "Info" + "fileLogLevelForEvents": "Info", + "fileLogLevelForSystemEvents": "Info" }"# } else { r#"{ @@ -309,7 +330,8 @@ mod tests { "hostGAPluginSupport": 1, "imdsSupport": 1, "ebpfProgramName": "ebpfProgramName", - "fileLogLevelForEvents": "Info" + "fileLogLevelForEvents": "Info", + "fileLogLevelForSystemEvents": "Info" }"# }; diff --git a/proxy_agent/src/common/logger.rs b/proxy_agent/src/common/logger.rs index d4019168..87432231 100644 --- a/proxy_agent/src/common/logger.rs +++ b/proxy_agent/src/common/logger.rs @@ -1,9 +1,7 @@ // Copyright (c) Microsoft Corporation // SPDX-License-Identifier: MIT -use crate::common::cli; use proxy_agent_shared::{ logger::{logger_manager, LoggerLevel}, - misc_helpers, telemetry::event_logger, }; @@ -28,10 +26,6 @@ pub fn write_error(message: String) { } fn log(log_level: LoggerLevel, message: String) { - if log_level != LoggerLevel::Trace { - write_console_log(message.to_string()); - }; - if let Some(log_for_event) = config::get_file_log_level_for_events() { if log_for_event >= log_level { // write to event @@ -49,18 +43,6 @@ fn log(log_level: LoggerLevel, message: String) { logger_manager::log(AGENT_LOGGER_KEY.to_string(), log_level, message); } -pub fn write_console_log(message: String) { - if cli::CLI.is_console_mode() { - println!( - "{} {}", - misc_helpers::get_date_time_string_with_milliseconds(), - message - ); - } else { - println!("{}", message); - } -} - #[cfg(not(windows))] pub fn write_serial_console_log(message: String) { use proxy_agent_shared::misc_helpers; diff --git a/proxy_agent/src/host_clients/goal_state.rs b/proxy_agent/src/host_clients/goal_state.rs index d1e6a179..69c3b7e2 100644 --- a/proxy_agent/src/host_clients/goal_state.rs +++ b/proxy_agent/src/host_clients/goal_state.rs @@ -89,15 +89,20 @@ pub struct SharedConfig { #[derive(Deserialize, Serialize, PartialEq)] #[allow(non_snake_case)] struct DeploymentField { + #[serde(rename = "@name")] name: String, + #[serde(rename = "@guid")] guid: String, + #[serde(rename = "@incarnation")] incarnation: String, } #[derive(Deserialize, Serialize, PartialEq)] #[allow(non_snake_case)] struct RoleField { + #[serde(rename = "@guid")] guid: String, + #[serde(rename = "@name")] name: String, } @@ -110,7 +115,9 @@ struct InstancesField { #[derive(Deserialize, Serialize, PartialEq)] #[allow(non_snake_case)] struct SharedConfigInstance { + #[serde(rename = "@id")] id: String, + #[serde(rename = "@address")] address: String, } diff --git a/proxy_agent/src/proxy/proxy_connection.rs b/proxy_agent/src/proxy/proxy_connection.rs index 807d1da7..e037bb8b 100644 --- a/proxy_agent/src/proxy/proxy_connection.rs +++ b/proxy_agent/src/proxy/proxy_connection.rs @@ -4,8 +4,8 @@ //! This module contains the connection context struct for the proxy listener, and write proxy processing logs to local file. use crate::common::error::{Error, HyperErrorType}; -use crate::common::hyper_client; use crate::common::result::Result; +use crate::common::{config, hyper_client}; use crate::proxy::Claims; use crate::redirector::{self, AuditEntry}; use crate::shared_state::proxy_server_wrapper::ProxyServerSharedState; @@ -309,7 +309,10 @@ impl ConnectionLogger { } } - if logger_level > logger_manager::get_logger_level() { + if logger_level > logger_manager::get_max_logger_level() + || config::get_logs_dir() == std::path::PathBuf::from("") + { + // If the logger level is higher than the max logger level or logs directory is not set, skip logging return; } diff --git a/proxy_agent/src/proxy/proxy_server.rs b/proxy_agent/src/proxy/proxy_server.rs index 0f765aaf..968773b6 100644 --- a/proxy_agent/src/proxy/proxy_server.rs +++ b/proxy_agent/src/proxy/proxy_server.rs @@ -794,7 +794,6 @@ impl ProxyServer { errorDetails: error_details, }; if let Ok(json) = serde_json::to_string(&summary) { - logger::write_console_log(json.to_string()); event_logger::write_event( LoggerLevel::Info, json, diff --git a/proxy_agent/src/service.rs b/proxy_agent/src/service.rs index 65fec2e1..7d07d965 100644 --- a/proxy_agent/src/service.rs +++ b/proxy_agent/src/service.rs @@ -27,11 +27,13 @@ use std::time::Duration; /// service::start_service(shared_state).await; /// ``` pub async fn start_service(shared_state: SharedState) { + if let Some(max_log_level) = config::get_file_log_level_for_system_events() { + logger_manager::set_system_logger(max_log_level, constants::PROXY_AGENT_SERVICE_NAME); + } + let log_folder = config::get_logs_dir(); if log_folder == PathBuf::from("") { - logger::write_console_log( - "The log folder is not set, skip write to GPA managed file log.".to_string(), - ); + println!("The log folder is not set, skip write to GPA managed file log."); } else { setup_loggers(log_folder, config::get_file_log_level()); } @@ -78,8 +80,6 @@ pub async fn start_service(shared_state: SharedState) { } fn setup_loggers(log_folder: PathBuf, max_logger_level: LoggerLevel) { - logger_manager::set_logger_level(max_logger_level); - let agent_logger = RollingLogger::create_new( log_folder.clone(), "ProxyAgent.log".to_string(), @@ -98,7 +98,11 @@ fn setup_loggers(log_folder: PathBuf, max_logger_level: LoggerLevel) { ConnectionLogger::CONNECTION_LOGGER_KEY.to_string(), connection_logger, ); - logger_manager::set_loggers(loggers, logger::AGENT_LOGGER_KEY.to_string()); + logger_manager::set_loggers( + loggers, + logger::AGENT_LOGGER_KEY.to_string(), + max_logger_level, + ); } /// Start the service and wait until the service is stopped. diff --git a/proxy_agent_extension/src/logger.rs b/proxy_agent_extension/src/logger.rs index bc4d3a1e..70c71c70 100644 --- a/proxy_agent_extension/src/logger.rs +++ b/proxy_agent_extension/src/logger.rs @@ -19,7 +19,7 @@ pub fn init_logger(log_folder: String, log_name: &str) { ); let mut loggers = std::collections::HashMap::new(); loggers.insert(log_name.to_string(), logger); - logger_manager::set_loggers(loggers, log_name.to_string()); + logger_manager::set_loggers(loggers, log_name.to_string(), LoggerLevel::Trace); if !LOGGER_KEY.initialized() { if let Err(e) = LOGGER_KEY.set(log_name.to_string()) { diff --git a/proxy_agent_setup/src/logger.rs b/proxy_agent_setup/src/logger.rs index 91c72dc7..11b7404c 100644 --- a/proxy_agent_setup/src/logger.rs +++ b/proxy_agent_setup/src/logger.rs @@ -15,7 +15,7 @@ fn force_init_logger(log_folder: PathBuf, log_name: &str) { let logger = RollingLogger::create_new(log_folder, log_name.to_string(), 20 * 1024 * 1024, 30); let mut loggers = std::collections::HashMap::new(); loggers.insert(log_name.to_string(), logger); - logger_manager::set_loggers(loggers, log_name.to_string()); + logger_manager::set_loggers(loggers, log_name.to_string(), LoggerLevel::Trace); } pub fn write(message: String) { diff --git a/proxy_agent_shared/Cargo.toml b/proxy_agent_shared/Cargo.toml index ef217730..4de75911 100644 --- a/proxy_agent_shared/Cargo.toml +++ b/proxy_agent_shared/Cargo.toml @@ -23,6 +23,8 @@ backtrace = "0.3" # used for get the caller module and function name [target.'cfg(windows)'.dependencies] windows-service = "0.7.0" # windows NT service winreg = "0.11.0" # windows reg read/write +serde-xml-rs = "0.8.1" # xml Deserializer with xml attribute +chrono = "0.4.41" # parse date time string [target.'cfg(windows)'.dependencies.windows-sys] version = "0.52.0" @@ -31,6 +33,7 @@ features = [ "Win32_Networking_WinSock", "Win32_System_IO", "Win32_Security", + "Win32_System_EventLog", "Win32_System_WindowsProgramming", "Win32_Security_Authentication_Identity", "Win32_System_Diagnostics_Debug", diff --git a/proxy_agent_shared/src/etw.rs b/proxy_agent_shared/src/etw.rs new file mode 100644 index 00000000..7ad87c14 --- /dev/null +++ b/proxy_agent_shared/src/etw.rs @@ -0,0 +1,5 @@ +// Copyright (c) Microsoft Corporation +// SPDX-License-Identifier: MIT +//! This module provides functionality for ETW (Event Tracing for Windows) logging. + +pub mod application; diff --git a/proxy_agent_shared/src/etw/application.rs b/proxy_agent_shared/src/etw/application.rs new file mode 100644 index 00000000..22221e7d --- /dev/null +++ b/proxy_agent_shared/src/etw/application.rs @@ -0,0 +1,463 @@ +// Copyright (c) Microsoft Corporation +// SPDX-License-Identifier: MIT +//! This module provides functionality for Windows Application event +//! // logging using the Windows Event Log API. +//! // It allows registering an event source, writing logs to the Application Event Log. + +use crate::error::Error; +use crate::logger::LoggerLevel; +use crate::result::Result; +use std::ffi::OsStr; +use std::iter::once; +use std::os::windows::ffi::OsStrExt; +use windows_sys::core::PWSTR; +use windows_sys::Win32::Foundation::HANDLE; +use windows_sys::Win32::System::EventLog::{ + DeregisterEventSource, RegisterEventSourceW, ReportEventW, +}; // advapi32.dll +use windows_sys::Win32::System::EventLog::{ + EVENTLOG_ERROR_TYPE, EVENTLOG_INFORMATION_TYPE, EVENTLOG_WARNING_TYPE, REPORT_EVENT_TYPE, +}; + +/// Converts a string to a wide character vector (u16). +/// This is used to convert Rust strings to the format required by Windows API functions. +fn to_wide(s: &str) -> Vec { + OsStr::new(s).encode_wide().chain(once(0)).collect() +} + +/// Converts a `LoggerLevel` to a `REPORT_EVENT_TYPE`. +/// This function maps the logging levels to the corresponding Windows Event Log types. +fn to_event_level(level: LoggerLevel) -> REPORT_EVENT_TYPE { + match level { + LoggerLevel::Trace => EVENTLOG_INFORMATION_TYPE, + LoggerLevel::Debug => EVENTLOG_INFORMATION_TYPE, + LoggerLevel::Info => EVENTLOG_INFORMATION_TYPE, + LoggerLevel::Warn => EVENTLOG_WARNING_TYPE, + LoggerLevel::Error => EVENTLOG_ERROR_TYPE, + } +} + +/// A struct for writing application events to the Windows Event Log. +/// It registers an event source and provides a method to write logs. +/// It also ensures that the event source is deregistered when the struct is dropped. +pub struct ApplicationEventWritter { + event_source: HANDLE, +} + +impl ApplicationEventWritter { + pub fn new(source_name: &str) -> Result { + let source_name_wide = to_wide(source_name); + let event_source = + unsafe { RegisterEventSourceW(std::ptr::null(), source_name_wide.as_ptr()) }; + if event_source == 0 { + return Err(Error::WindowsApi( + "RegisterEventSourceW".to_string(), + std::io::Error::last_os_error(), + )); + } + + // register event source in the Windows Registry + // `HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\EventLog\Application\{source_name}` + let key_name = format!( + r"SYSTEM\CurrentControlSet\Services\EventLog\Application\{}", + source_name + ); + let value = crate::misc_helpers::resolve_env_variables( + r"%SystemRoot%\Microsoft.NET\Framework64\v4.0.30319\EventLogMessages.dll", + )?; + crate::windows::set_reg_string(&key_name, "EventMessageFile", value)?; + + Ok(ApplicationEventWritter { event_source }) + } + + pub fn write(&self, log_level: LoggerLevel, message: String) { + let wide_message = to_wide(&message); + let wide_message_ptrs: [PWSTR; 1] = [wide_message.as_ptr() as PWSTR]; + + unsafe { + ReportEventW( + self.event_source, + to_event_level(log_level), + 0, + 0, + std::ptr::null_mut(), + 1, + 0, + wide_message_ptrs.as_ptr() as *const *const u16, + std::ptr::null(), + ); + } + } +} + +impl Drop for ApplicationEventWritter { + fn drop(&mut self) { + unsafe { + DeregisterEventSource(self.event_source); + } + } +} + +#[cfg(test)] +mod tests { + + /// etw_reader test module is used to read ETW events from the Windows Event Log. + mod etw_reader { + + use crate::error::Error; + use crate::result::Result; + use chrono::DateTime; + use serde_derive::{Deserialize, Serialize}; + use std::ffi::OsString; + use std::os::windows::ffi::OsStringExt; + use windows_sys::Win32::Foundation::GetLastError; + use windows_sys::Win32::Foundation::ERROR_NO_MORE_ITEMS; + use windows_sys::Win32::System::EventLog::{ + EvtClose, EvtNext, EvtQuery, EvtRender, EVT_HANDLE, + }; // wevtapi.dll + use windows_sys::Win32::System::EventLog::{EvtQueryReverseDirection, EvtRenderEventXml}; + + /// Represents an ETW event structure + /// as defined in the XML schema. + /// The structure is used to deserialize ETW events from XML format. + /// The `Event` struct contains a `System` and `EventData` field, + /// which hold the metadata and data of the event respectively. + #[derive(Debug, Deserialize, Serialize)] + #[serde(rename = "Event")] + pub struct Event { + #[serde(rename = "System")] + pub system: System, + #[serde(rename = "EventData", skip_serializing_if = "Option::is_none")] + pub event_data: Option, + } + + #[derive(Debug, Deserialize, Serialize)] + pub struct System { + #[serde(rename = "Provider")] + pub provider: Provider, + #[serde(rename = "EventID")] + pub event_id: u32, + #[serde(rename = "Version")] + pub version: u8, + #[serde(rename = "Level")] + pub level: u8, + #[serde(rename = "Task")] + pub task: u8, + #[serde(rename = "Opcode")] + pub opcode: u8, + #[serde(rename = "Keywords")] + pub keywords: String, + #[serde(rename = "TimeCreated")] + pub time_created: TimeCreated, + #[serde(rename = "EventRecordID")] + pub event_record_id: u64, + #[serde(rename = "Execution")] + pub execution: Execution, + #[serde(rename = "Channel")] + pub channel: String, + #[serde(rename = "Computer")] + pub computer: String, + } + + #[derive(Debug, Deserialize, Serialize)] + pub struct Provider { + #[serde(rename = "@Name", skip_serializing_if = "Option::is_none")] + pub name: Option, + #[serde(rename = "@EventSourceName", skip_serializing_if = "Option::is_none")] + pub event_source_name: Option, + } + + #[derive(Debug, Deserialize, Serialize)] + pub struct TimeCreated { + #[serde(rename = "@SystemTime", skip_serializing_if = "Option::is_none")] + pub system_time: Option, + } + + #[derive(Debug, Deserialize, Serialize)] + pub struct Execution { + #[serde(rename = "@ProcessID")] + pub process_id: u32, + #[serde(rename = "@ThreadID")] + pub thread_id: u32, + } + + #[derive(Debug, Deserialize, Serialize)] + pub struct EventData { + #[serde(rename = "Data")] + pub data: Option>, + } + + pub struct WindowsEventReader { + query_handle: EVT_HANDLE, + current_event: EVT_HANDLE, + source_name: String, + start_time: Option>, + end_time: Option>, + } + + impl WindowsEventReader { + pub fn new( + event_name: &str, + source_name: &str, + start_time: Option>, + end_time: Option>, + ) -> Result { + let event_name_wide = crate::etw::application::to_wide(event_name); + let h_query = unsafe { + EvtQuery( + 0, + event_name_wide.as_ptr(), + std::ptr::null(), + EvtQueryReverseDirection, + ) + }; + if h_query == 0 { + return Err(Error::WindowsApi( + "EvtQuery".to_string(), + std::io::Error::last_os_error(), + )); + } + + Ok(WindowsEventReader { + query_handle: h_query, + current_event: 0, + source_name: source_name.to_string(), + start_time, + end_time, + }) + } + // Additional methods for reading events can be implemented here + } + + impl Drop for WindowsEventReader { + fn drop(&mut self) { + // Close the query handle and current event handle if they are open + unsafe { + EvtClose(self.query_handle); + EvtClose(self.current_event); + } + } + } + + impl Iterator for WindowsEventReader { + type Item = Result; + + fn next(&mut self) -> Option { + let mut returned: u32 = 0; + + if unsafe { + EvtNext( + self.query_handle, + 1, + &mut self.current_event, + 0, + 0, + &mut returned, + ) + } == 0 + { + let error_code = unsafe { GetLastError() }; + if error_code == ERROR_NO_MORE_ITEMS { + // No more items to read + return None; + } else { + return Some(Err(Error::WindowsApi( + "EvtNext".to_string(), + std::io::Error::from_raw_os_error(error_code as i32), + ))); + } + } + + if returned == 0 { + return None; // No events read + } + + // First call to get buffer size + let mut buffer_used = 0; + let mut property_count = 0; + let status = unsafe { + EvtRender( + 0, + self.current_event, + EvtRenderEventXml, + 0, + std::ptr::null_mut(), + &mut buffer_used, + &mut property_count, + ) + }; + if status != 0 || buffer_used == 0 { + return Some(Err(Error::WindowsApi( + "EvtRender_Buffer_Size".to_string(), + std::io::Error::last_os_error(), + ))); + } + // Allocate buffer for rendering + let mut buffer: Vec = vec![0; buffer_used as usize / 2]; + if unsafe { + EvtRender( + 0, + self.current_event, + EvtRenderEventXml, + buffer_used, + buffer.as_mut_ptr() as *mut _, + &mut buffer_used, + &mut property_count, + ) + } == 0 + { + return Some(Err(Error::WindowsApi( + "EvtRender".to_string(), + std::io::Error::last_os_error(), + ))); + } + + // Convert the buffer to a xml string + let xml = OsString::from_wide(&buffer) + .to_string_lossy() + .trim_end_matches('\0') + .to_string(); + + // Parse the XML string into an Event struct + match serde_xml_rs::from_str::(&xml) { + Ok(event) => { + let mut skip_event = false; + // Check if the event is from the specified source + if event.system.provider.name == Some(self.source_name.clone()) { + // Check if the event is within the specified time range + let time_created = event.system.time_created.system_time.clone(); + if let Some(start_time) = self.start_time { + match time_created.clone() { + Some(time) => { + if let Ok(event_time) = + time.parse::>() + { + if event_time < start_time { + skip_event = true; // Skip this event + } + } + } + None => skip_event = true, // Skip this event if time is not available + } + } + if let Some(end_time) = self.end_time { + match time_created { + Some(time) => { + if let Ok(event_time) = + time.parse::>() + { + if event_time > end_time { + skip_event = true; // Skip this event + } + } + } + None => skip_event = true, // Skip this event if time is not available + } + } + } else { + skip_event = true; // Skip this event + } + + if skip_event { + self.next() // Skip to the next event + } else { + Some(Ok(event)) // Return the event + } + } + Err(e) => Some(Err(Error::Io(std::io::Error::new( + std::io::ErrorKind::InvalidData, + format!("Failed to parse event XML: {}", e), + )))), + } + } + } + } + + use chrono::DateTime; + + #[test] + fn write_event_log_test() { + use super::ApplicationEventWritter; + use crate::logger::LoggerLevel; + + let start_time = chrono::Utc::now(); + let end_time = start_time + chrono::Duration::seconds(60); + + let source_name = "GuestProxyAgent_TestApplication"; + let message = "This is a test log message"; + let event_writer = ApplicationEventWritter::new(source_name).unwrap(); + event_writer.write(LoggerLevel::Info, message.to_string()); + + println!("Verifying event log for source: {}", source_name); + let data = query_application_event(source_name, None, None); + assert_eq!( + data, message, + "Event log data does not match the expected message" + ); + + println!( + "Verifying event log for source: {} after {}", + source_name, start_time + ); + let data = query_application_event(source_name, Some(start_time), None); + assert_eq!( + data, message, + "Event log data does not match the expected message" + ); + + println!( + "Verifying event log for source: {} before {}", + source_name, end_time + ); + let data = query_application_event(source_name, None, Some(end_time)); + assert_eq!( + data, message, + "Event log data does not match the expected message" + ); + + println!( + "Verifying event log for source: {} between {} and {}", + source_name, start_time, end_time + ); + let data = query_application_event(source_name, Some(start_time), Some(end_time)); + assert_eq!( + data, message, + "Event log data does not match the expected message" + ); + + // Clean up: Remove the event source from the Windows Registry + let key_name = format!( + r"SYSTEM\CurrentControlSet\Services\EventLog\Application\{}", + source_name + ); + if let Err(e) = crate::windows::remove_reg_key(&key_name) { + eprintln!("Failed to remove event source from registry: {}", e); + } + } + + fn query_application_event( + source_name: &str, + start_time: Option>, + end_time: Option>, + ) -> String { + let mut reader = + etw_reader::WindowsEventReader::new("Application", source_name, start_time, end_time) + .unwrap(); + let data = reader + .next() + .map(|event| { + event + .unwrap() + .event_data + .unwrap() + .data + .unwrap() + .iter() + .map(|d| d.to_string()) + .collect::>() + }) + .unwrap_or_else(|| vec!["No data found".to_string()]); + + return data.join("\n"); + } +} diff --git a/proxy_agent_shared/src/lib.rs b/proxy_agent_shared/src/lib.rs index 4ba2f5bb..27a01e6a 100644 --- a/proxy_agent_shared/src/lib.rs +++ b/proxy_agent_shared/src/lib.rs @@ -2,6 +2,8 @@ // SPDX-License-Identifier: MIT pub mod error; +#[cfg(windows)] +pub mod etw; pub mod logger; pub mod misc_helpers; pub mod proxy_agent_aggregate_status; diff --git a/proxy_agent_shared/src/logger/logger_manager.rs b/proxy_agent_shared/src/logger/logger_manager.rs index 97784746..61dff8bb 100644 --- a/proxy_agent_shared/src/logger/logger_manager.rs +++ b/proxy_agent_shared/src/logger/logger_manager.rs @@ -1,22 +1,50 @@ // Copyright (c) Microsoft Corporation // SPDX-License-Identifier: MIT +//! This module manages the loggers for the application. +//! It provides functionality to set up loggers, write logs, and manage log levels. +//! It uses a static `OnceCell` to ensure that the loggers are initialized only once. use super::rolling_logger::RollingLogger; -use log::Level; +#[cfg(windows)] +use crate::etw::application::ApplicationEventWritter; +use crate::logger::LoggerLevel; use std::collections::HashMap; +// The loggers are stored in a static `OnceCell` to ensure they are initialized only once. static LOGGERS: tokio::sync::OnceCell> = tokio::sync::OnceCell::const_new(); +// The `DEFAULT_LOGGER_KEY` is used to specify which rolling logger should be used by default when no key is provided. static DEFAULT_LOGGER_KEY: tokio::sync::OnceCell = tokio::sync::OnceCell::const_new(); -static MAX_LOG_LEVEL: tokio::sync::OnceCell = tokio::sync::OnceCell::const_new(); +// The `MAX_LOG_LEVEL` is used to set the maximum log level for the loggers. +static MAX_LOG_LEVEL: tokio::sync::OnceCell = tokio::sync::OnceCell::const_new(); +// The `MAX_SYSTEM_LOG_LEVEL` is used to set the maximum log level for system logs. +static MAX_SYSTEM_LOG_LEVEL: tokio::sync::OnceCell = + tokio::sync::OnceCell::const_new(); +#[cfg(windows)] +static WINDOWS_ETW_APPLICATION_LOGGER: tokio::sync::OnceCell = + tokio::sync::OnceCell::const_new(); /// Setup the loggers and set the default logger key /// # Arguments /// * `loggers` - A hashmap of loggers /// * `default_logger_key` - The default logger key +/// * `max_log_level` - The maximum log level for file logging /// # Panics /// * If the default logger key is not found in the loggers hashmap -pub fn set_loggers(loggers: HashMap, default_logger_key: String) { +pub fn set_loggers( + loggers: HashMap, + default_logger_key: String, + max_log_level: LoggerLevel, +) { + if !MAX_LOG_LEVEL.initialized() { + if let Err(e) = MAX_LOG_LEVEL.set(max_log_level) { + write_system_log( + LoggerLevel::Error, + format!("Failed to set logger level: {}", e), + ); + } + } + if LOGGERS.initialized() { return; } @@ -26,21 +54,54 @@ pub fn set_loggers(loggers: HashMap, default_logger_key: } // set the loggers once - LOGGERS.set(loggers).unwrap(); - DEFAULT_LOGGER_KEY.set(default_logger_key).unwrap(); + if let Err(e) = LOGGERS.set(loggers) { + write_system_log(LoggerLevel::Error, format!("Failed to set loggers: {}", e)); + }; + if let Err(e) = DEFAULT_LOGGER_KEY.set(default_logger_key) { + write_system_log( + LoggerLevel::Error, + format!("Failed to set default logger key: {}", e), + ); + } } -pub fn set_logger_level(log_level: Level) { - if MAX_LOG_LEVEL.initialized() { - return; +pub fn set_system_logger(max_log_level: LoggerLevel, _service_name: &str) { + #[cfg(windows)] + { + if !WINDOWS_ETW_APPLICATION_LOGGER.initialized() { + match ApplicationEventWritter::new(_service_name) { + Ok(logger) => { + if let Err(e) = WINDOWS_ETW_APPLICATION_LOGGER.set(logger) { + write_system_log( + LoggerLevel::Error, + format!("Failed to set Windows Application ETW logger: {}", e), + ); + } + } + Err(e) => { + write_system_log( + LoggerLevel::Error, + format!("Failed to create Windows Application ETW logger: {}", e), + ); + } + } + } + } + + if !MAX_SYSTEM_LOG_LEVEL.initialized() { + if let Err(e) = MAX_SYSTEM_LOG_LEVEL.set(max_log_level) { + write_system_log( + LoggerLevel::Error, + format!("Failed to set system logger level: {}", e), + ); + } } - MAX_LOG_LEVEL.set(log_level).unwrap(); } -pub fn get_logger_level() -> Level { +pub fn get_max_logger_level() -> LoggerLevel { let level = match MAX_LOG_LEVEL.get() { Some(l) => *l, // No need to use `clone` on type `Level` which implements the `Copy` trait - None => Level::Trace, + None => LoggerLevel::Trace, }; level } @@ -56,44 +117,40 @@ fn get_logger(logger_key: Option) -> Option<&'static RollingLogger> { None } -pub fn log(logger_key: String, log_level: Level, message: String) { - if log_level > get_logger_level() { +fn internal_log(logger_key: Option, log_level: LoggerLevel, message: String) { + // By default, we write the log to the system log + // This is useful for debugging and monitoring purposes. + write_system_log(log_level, message.clone()); + + if log_level > get_max_logger_level() { return; } - if let Some(logger) = get_logger(Some(logger_key)) { + if let Some(logger) = get_logger(logger_key) { if let Err(e) = logger.write(log_level, message) { eprintln!("Error writing to log: {}", e); } } } -pub fn write_log(log_level: Level, message: String) { - let level = match MAX_LOG_LEVEL.get() { - Some(l) => *l, // No need to use `clone` on type `Level` which implements the `Copy` trait - None => Level::Trace, - }; - if log_level > level { - return; - } +pub fn log(logger_key: String, log_level: LoggerLevel, message: String) { + internal_log(Some(logger_key), log_level, message); +} - if let Some(logger) = get_logger(None) { - if let Err(e) = logger.write(log_level, message) { - eprintln!("Error writing to log: {}", e); - } - } +pub fn write_log(log_level: LoggerLevel, message: String) { + internal_log(None, log_level, message); } pub fn write_info(message: String) { - write_log(Level::Info, message); + write_log(LoggerLevel::Info, message); } pub fn write_warn(message: String) { - write_log(Level::Warn, message); + write_log(LoggerLevel::Warn, message); } pub fn write_err(message: String) { - write_log(Level::Error, message); + write_log(LoggerLevel::Error, message); } pub fn write_many(logger_key: Option, messages: Vec) { @@ -104,11 +161,41 @@ pub fn write_many(logger_key: Option, messages: Vec) { } } +fn write_system_log(log_level: LoggerLevel, message: String) { + if log_level > get_max_system_logger_level() { + return; + } + + // Linux automatically captures console logs to syslog. + if log_level == LoggerLevel::Error { + eprintln!("{}", message); + } else { + println!("{}", message); + } + + #[cfg(windows)] + { + if let Some(logger) = WINDOWS_ETW_APPLICATION_LOGGER.get() { + logger.write(log_level, message); + } else { + eprintln!("Windows ETW Application logger is not initialized."); + } + } +} + +fn get_max_system_logger_level() -> LoggerLevel { + let level = match MAX_SYSTEM_LOG_LEVEL.get() { + Some(l) => *l, // No need to use `clone` on type `Level` which implements the `Copy` trait + None => LoggerLevel::Error, + }; + level +} + #[cfg(test)] mod tests { + use crate::logger::LoggerLevel; use crate::misc_helpers; use ctor::{ctor, dtor}; - use log::Level; use std::env; use std::fs; @@ -131,7 +218,11 @@ mod tests { ); let mut loggers = std::collections::HashMap::new(); loggers.insert(TEST_LOGGER_KEY.to_string(), logger); - crate::logger::logger_manager::set_loggers(loggers, TEST_LOGGER_KEY.to_string()); + crate::logger::logger_manager::set_loggers( + loggers, + TEST_LOGGER_KEY.to_string(), + LoggerLevel::Trace, + ); } #[dtor] @@ -144,16 +235,16 @@ mod tests { fn logger_manager_test() { for _ in [0; 20] { super::write_log( - Level::Trace, + LoggerLevel::Trace, String::from("This is a test message This is a test message"), ); super::write_log( - Level::Debug, + LoggerLevel::Debug, String::from("This is a test message This is a test message"), ); - super::write_log(Level::Info, "message from write_info".to_string()); - super::write_log(Level::Warn, "message from write_warn".to_string()); - super::write_log(Level::Error, "message from write_err".to_string()); + super::write_log(LoggerLevel::Info, "message from write_info".to_string()); + super::write_log(LoggerLevel::Warn, "message from write_warn".to_string()); + super::write_log(LoggerLevel::Error, "message from write_err".to_string()); } let file_count = misc_helpers::get_files(&get_temp_test_dir()).unwrap(); diff --git a/proxy_agent_shared/src/windows.rs b/proxy_agent_shared/src/windows.rs index c9e1fb14..aa35ede6 100644 --- a/proxy_agent_shared/src/windows.rs +++ b/proxy_agent_shared/src/windows.rs @@ -49,6 +49,19 @@ fn read_reg_string(key_name: &str, value_name: &str, default_value: String) -> S default_value } +pub fn set_reg_string(key_name: &str, value_name: &str, value: String) -> Result<()> { + let hklm = RegKey::predef(HKEY_LOCAL_MACHINE); + let (key, _) = hklm.create_subkey(key_name)?; + key.set_value(value_name, &value)?; + Ok(()) +} + +pub fn remove_reg_key(key_name: &str) -> Result<()> { + let hklm = RegKey::predef(HKEY_LOCAL_MACHINE); + hklm.delete_subkey_all(key_name)?; + Ok(()) +} + const OS_VERSION_REGISTRY_KEY: &str = "Software\\Microsoft\\Windows NT\\CurrentVersion"; const PRODUCT_NAME_VAL_STRING: &str = "ProductName"; const CURRENT_MAJOR_VERSION_NUMBER_STRING: &str = "CurrentMajorVersionNumber"; @@ -369,4 +382,21 @@ mod tests { println!("kernel32.dll File product version: {}", version); assert_eq!(version.major, 10, "major version mismatch"); } + + #[test] + fn reg_set_test() { + let key_name = "Software\\TestKey"; + let value_name = "TestValue"; + let value = "TestValueData".to_string(); + + // Set the registry value + super::set_reg_string(key_name, value_name, value.clone()).unwrap(); + + // Read the registry value + let read_value = super::read_reg_string(key_name, value_name, "".to_string()); + assert_eq!(value, read_value, "Registry value mismatch"); + + // Clean up + super::remove_reg_key(key_name).unwrap(); + } }