This is an automated email from the ASF dual-hosted git repository. hsun pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/incubator-teaclave.git
commit 27cf49bb765ae6fb68ca8c4eb388798e85d14e48 Author: sunhe05 <[email protected]> AuthorDate: Fri Mar 3 03:44:24 2023 +0000 Add teaclave logger --- cmake/tomls/Cargo.sgx_trusted_lib.lock | 65 +++++---- examples/rust/builtin_echo/src/main.rs | 2 +- .../rust/builtin_ordered_set_intersect/src/main.rs | 18 ++- function/src/echo.rs | 6 + function/src/ordered_set_intersect.rs | 3 + .../service_enclave_utils => logger}/Cargo.toml | 39 +++-- logger/README.md | 19 +++ logger/src/lib.rs | 161 +++++++++++++++++++++ logger/src/task_logger.rs | 62 ++++++++ sdk/rust/src/bindings.rs | 2 +- sdk/rust/src/lib.rs | 9 +- services/execution/enclave/Cargo.toml | 2 +- services/execution/enclave/src/lib.rs | 2 + services/execution/enclave/src/service.rs | 23 ++- services/proto/src/proto/teaclave_common.proto | 1 + services/proto/src/teaclave_common.rs | 2 + services/utils/service_enclave_utils/Cargo.toml | 15 +- services/utils/service_enclave_utils/src/lib.rs | 31 ++-- tests/functional/enclave/src/execution_service.rs | 11 +- tests/functional/enclave/src/scheduler_service.rs | 2 +- tests/unit/enclave/Cargo.toml | 3 + tests/unit/enclave/src/lib.rs | 1 + types/src/task.rs | 8 +- 23 files changed, 399 insertions(+), 88 deletions(-) diff --git a/cmake/tomls/Cargo.sgx_trusted_lib.lock b/cmake/tomls/Cargo.sgx_trusted_lib.lock index dc5c507f..6e9190cc 100644 --- a/cmake/tomls/Cargo.sgx_trusted_lib.lock +++ b/cmake/tomls/Cargo.sgx_trusted_lib.lock @@ -138,10 +138,7 @@ version = "0.9.3" source = "registry+https://github.com/rust-lang/crates.io-index"; checksum = "a12e6657c4c97ebab115a42dcee77225f7f482cdd841cf7088c657a42e9e00e7" dependencies = [ - "humantime", "log", - "regex", - "termcolor", ] [[package]] @@ -230,12 +227,6 @@ version = "1.8.0" source = "registry+https://github.com/rust-lang/crates.io-index"; checksum = "d897f394bad6a705d5f4104762e116a75639e470d80901eed05a860a95cb1904" -[[package]] -name = "humantime" -version = "2.1.0" -source = "registry+https://github.com/rust-lang/crates.io-index"; -checksum = "9a3a5bfb195931eeb336b2a7b4d761daec841b97f947d34394601737a7bba5e4" - [[package]] name = "idna" version = "0.3.0" @@ -357,6 +348,7 @@ source = "registry+https://github.com/rust-lang/crates.io-index"; checksum = "abb12e687cfb44aa40f41fc3978ef76448f9b6038cad6aef4259d3c095a2382e" dependencies = [ "cfg-if 1.0.0", + "value-bag", ] [[package]] @@ -1001,6 +993,12 @@ version = "0.5.2" source = "registry+https://github.com/rust-lang/crates.io-index"; checksum = "6e63cff320ae2c57904679ba7cb63280a3dc4613885beafb148ee7bf9aa9042d" +[[package]] +name = "sval" +version = "1.0.0-alpha.5" +source = "registry+https://github.com/rust-lang/crates.io-index"; +checksum = "45f6ee7c7b87caf59549e9fe45d6a69c75c8019e79e212a835c5da0e92f0ba08" + [[package]] name = "syn" version = "0.15.44" @@ -1322,6 +1320,17 @@ dependencies = [ "thiserror", ] +[[package]] +name = "teaclave_logger" +version = "0.4.0" +dependencies = [ + "anyhow", + "log", + "sgx_cov", + "sgx_types", + "teaclave_test_utils", +] + [[package]] name = "teaclave_management_service_enclave" version = "0.4.0" @@ -1442,6 +1451,8 @@ dependencies = [ "sgx_macros", "teaclave_attestation", "teaclave_config", + "teaclave_logger", + "teaclave_proto", "teaclave_rpc", "teaclave_service_enclave_utils_proc_macro", "teaclave_types", @@ -1552,6 +1563,7 @@ dependencies = [ "teaclave_executor_context", "teaclave_frontend_service_enclave", "teaclave_function", + "teaclave_logger", "teaclave_management_service_enclave", "teaclave_rpc", "teaclave_runtime", @@ -1580,15 +1592,6 @@ dependencies = [ "thiserror", ] -[[package]] -name = "termcolor" -version = "1.1.3" -source = "registry+https://github.com/rust-lang/crates.io-index"; -checksum = "bab24d30b911b2376f3a13cc2cd443142f0c81dda04c118693e35b3835757755" -dependencies = [ - "winapi-util", -] - [[package]] name = "thiserror" version = "1.0.38" @@ -1698,6 +1701,23 @@ dependencies = [ "sha1", ] +[[package]] +name = "value-bag" +version = "1.0.0-alpha.9" +source = "registry+https://github.com/rust-lang/crates.io-index"; +checksum = "2209b78d1249f7e6f3293657c9779fe31ced465df091bbd433a1cf88e916ec55" +dependencies = [ + "ctor", + "sval", + "version_check", +] + +[[package]] +name = "version_check" +version = "0.9.4" +source = "registry+https://github.com/rust-lang/crates.io-index"; +checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" + [[package]] name = "wasi" version = "0.10.2+wasi-snapshot-preview1" @@ -1803,15 +1823,6 @@ version = "0.4.0" source = "registry+https://github.com/rust-lang/crates.io-index"; checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" -[[package]] -name = "winapi-util" -version = "0.1.5" -source = "registry+https://github.com/rust-lang/crates.io-index"; -checksum = "70ec6ce85bb158151cae5e5c87f95a8e97d2c0c4b001223f33a334e3ce5de178" -dependencies = [ - "winapi", -] - [[package]] name = "winapi-x86_64-pc-windows-gnu" version = "0.4.0" diff --git a/examples/rust/builtin_echo/src/main.rs b/examples/rust/builtin_echo/src/main.rs index cedce10f..11e95a69 100644 --- a/examples/rust/builtin_echo/src/main.rs +++ b/examples/rust/builtin_echo/src/main.rs @@ -90,7 +90,7 @@ fn echo(message: &str) -> Result<Vec<u8>> { println!("[+] getting result"); let response = client.get_task_result(&task_id)?; - Ok(response) + Ok(response.0) } fn main() -> Result<()> { diff --git a/examples/rust/builtin_ordered_set_intersect/src/main.rs b/examples/rust/builtin_ordered_set_intersect/src/main.rs index 83aa188c..636dcd04 100644 --- a/examples/rust/builtin_ordered_set_intersect/src/main.rs +++ b/examples/rust/builtin_ordered_set_intersect/src/main.rs @@ -118,7 +118,7 @@ impl Client { "Native Private Set Intersection.", "builtin", None, - Some(&["order"]), + Some(&["order", "save_log"]), Some(vec![ teaclave_client_sdk::FunctionInput::new("input_data1", "Client 0 data.", false), teaclave_client_sdk::FunctionInput::new("input_data2", "Client 1 data.", false), @@ -129,7 +129,7 @@ impl Client { ]), )?; self.client.get_function(&function_id)?; - let function_arguments = hashmap!("order" => "ascending"); // Order can be ascending or desending + let function_arguments = hashmap!("order" => "ascending", "save_log" => "true"); // Order can be ascending or desending let inputs_ownership = hashmap!(&self.user_data.input_label => vec![self.user_data.user_id.to_string()], &self.user_data.peer_input_label => vec![self.user_data.peer_id.to_string()]); let outputs_ownership = hashmap!(&self.user_data.output_label => vec![self.user_data.user_id.to_string()], &self.user_data.peer_output_label => vec![self.user_data.peer_id.to_string()]); @@ -193,7 +193,7 @@ impl Client { Ok(()) } - fn get_task_result(&mut self, task_id: &str) -> Result<Vec<u8>> { + fn get_task_result(&mut self, task_id: &str) -> Result<(Vec<u8>, Vec<String>)> { println!("[+] {} getting result", self.user_data.user_id); let response = self.client.get_task_result(&task_id)?; Ok(response) @@ -260,11 +260,19 @@ fn main() -> Result<()> { let result_user0 = user0.get_task_result(&task_id)?; - println!("[+] User 0 result: {:?}", String::from_utf8(result_user0)); + println!( + "[+] User 0 result: {:?} log: {:?} ", + String::from_utf8(result_user0.0), + result_user0.1 + ); let result_user1 = user1.get_task_result(&task_id)?; - println!("[+] User 1 result: {:?}", String::from_utf8(result_user1)); + println!( + "[+] User 1 result: {:?} log {:?}", + String::from_utf8(result_user1.0), + result_user1.1 + ); println!("[+] done"); Ok(()) diff --git a/function/src/echo.rs b/function/src/echo.rs index 238b3184..a0c1de71 100644 --- a/function/src/echo.rs +++ b/function/src/echo.rs @@ -48,6 +48,12 @@ impl Echo { _runtime: FunctionRuntime, ) -> anyhow::Result<String> { let message = EchoArguments::try_from(arguments)?.message; + + #[cfg(test_mode)] + log::info!("{}", message); + #[cfg(test_mode)] + log::debug!("{}", message); + Ok(message) } } diff --git a/function/src/ordered_set_intersect.rs b/function/src/ordered_set_intersect.rs index 24ec98c4..32124111 100644 --- a/function/src/ordered_set_intersect.rs +++ b/function/src/ordered_set_intersect.rs @@ -87,6 +87,9 @@ impl OrderedSetIntersect { for item in result2 { write!(&mut output2, "{}", item as u32)?; } + + log::trace!("{}", common_sets); + Ok(format!("{} common items", common_sets)) } } diff --git a/services/utils/service_enclave_utils/Cargo.toml b/logger/Cargo.toml similarity index 51% copy from services/utils/service_enclave_utils/Cargo.toml copy to logger/Cargo.toml index 1d54e0b8..2184685c 100644 --- a/services/utils/service_enclave_utils/Cargo.toml +++ b/logger/Cargo.toml @@ -16,35 +16,30 @@ # under the License. [package] -name = "teaclave_service_enclave_utils" +name = "teaclave_logger" version = "0.4.0" authors = ["Teaclave Contributors <[email protected]>"] -description = "Teaclave enclave utils" +description = "Teaclave worker" license = "Apache-2.0" edition = "2021" +[lib] +name = "teaclave_logger" +crate-type = ["staticlib", "rlib"] + [features] -default = [] -mesalock_sgx = [ - "env_logger/termcolor", - "env_logger/humantime", - "env_logger/regex", - "teaclave_types/mesalock_sgx", - "teaclave_attestation/mesalock_sgx", - "teaclave_rpc/mesalock_sgx", -] -cov = ["sgx_cov", "sgx_macros"] +default = ["mesalock_sgx"] +mesalock_sgx = [] +cov = ["sgx_cov"] +enclave_unit_test = ["teaclave_test_utils/mesalock_sgx"] [dependencies] -anyhow = { version = "1.0.26" } -env_logger = { version = "0.9.3", default_features = false } -log = { version = "0.4.17", features = ["release_max_level_info"] } +anyhow = { version = "1.0.26" } +log = { version = "0.4.17", features = ["release_max_level_info", "kv_unstable_std"] } + +teaclave_test_utils = { path = "../tests/utils", optional = true } -teaclave_service_enclave_utils_proc_macro = { path = "./proc_macro" } -teaclave_types = { path = "../../../types" } -teaclave_attestation = { path = "../../../attestation" } -teaclave_rpc = { path = "../../../rpc" } -teaclave_config = { path = "../../../config" } +sgx_cov = { version = "2.0.0", optional = true } -sgx_cov = { version = "2.0.0", optional = true } -sgx_macros = { version = "2.0.0", optional = true } +[target.'cfg(not(target_vendor = "teaclave"))'.dependencies] +sgx_types = { version = "2.0.0" } diff --git a/logger/README.md b/logger/README.md new file mode 100644 index 00000000..1ad404d0 --- /dev/null +++ b/logger/README.md @@ -0,0 +1,19 @@ +--- +permalink: /docs/codebase/logger +--- + +# Logger + +A logger for Teaclave services. It can collect logs to a buffer. +Logs not saved to buffer can be logged by another logger that +implements `log` trait. + +## Task logging + +When the logger is imported in the `execution service`, it can send the logs +during a task to a buffer. The `kv_unstable` feature in the `log` crate is used +to pass the pointer to the buffer to the logger. After the buffer is set, the +logger will save logs to the buffer. The logger will drop the task logger after +receiving a null pointer. Another logger which we call `secondary logger` will +handle the logs coming afterwards if it is set. The logs before the task starts +are sent to the secondary logger as well. diff --git a/logger/src/lib.rs b/logger/src/lib.rs new file mode 100644 index 00000000..dab63d90 --- /dev/null +++ b/logger/src/lib.rs @@ -0,0 +1,161 @@ +// Licensed to the Apache Software Foundation (ASF) under one +// or more contributor license agreements. See the NOTICE file +// distributed with this work for additional information +// regarding copyright ownership. The ASF licenses this file +// to you under the Apache License, Version 2.0 (the +// "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, +// software distributed under the License is distributed on an +// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +// KIND, either express or implied. See the License for the +// specific language governing permissions and limitations +// under the License. + +#![feature(strict_provenance)] + +mod task_logger; +use task_logger::TaskLogger; + +use std::sync::RwLock; + +use log::{LevelFilter, Log, Metadata, Record}; + +struct TeaclaveLogger<T> { + task_logger: RwLock<Option<TaskLogger>>, + secondary_logger: Option<T>, +} + +impl<T: Log> TeaclaveLogger<T> { + pub fn log_task(&self, task_logger: TaskLogger) { + let mut lock = self.task_logger.write().unwrap(); + assert!(lock.is_none(), "only one task is allowed to be logged"); + + if let Some(sl) = &self.secondary_logger { + sl.flush() + } + + *lock = Some(task_logger); + } + + pub fn end_logging_task(&self) { + let mut lock = self.task_logger.write().unwrap(); + assert!(lock.is_some(), "task should be logged before being ended"); + + *lock = None; + } +} + +impl<T: Log> Log for TeaclaveLogger<T> { + fn enabled(&self, metadata: &Metadata) -> bool { + if let Some(tl) = &*self.task_logger.read().unwrap() { + tl.enabled(metadata) + } else if let Some(sl) = &self.secondary_logger { + sl.enabled(metadata) + } else { + false + } + } + + fn log(&self, record: &Record) { + let kv = record.key_values(); + + if let Some(v) = kv.get("buffer".into()) { + let addr = v.to_u64().unwrap(); + + if addr == 0 { + self.end_logging_task(); + } else { + let task_logger = TaskLogger::new(addr); + self.log_task(task_logger); + } + + // Ignore the message when task_id is set + return; + } + + let mut lock = self.task_logger.write().unwrap(); + if let Some(ref mut tl) = *lock { + tl.log(record); + return; + } + + if let Some(sl) = &self.secondary_logger { + sl.log(record) + } + } + + fn flush(&self) { + let mut lock = self.task_logger.write().unwrap(); + + if let Some(ref mut tl) = *lock { + tl.flush(); + return; + } + + if let Some(sl) = &self.secondary_logger { + sl.flush() + } + } +} + +pub struct Builder<T> { + secondary_logger: Option<T>, +} + +impl<T: Log + 'static> Builder<T> { + pub fn new() -> Self { + Default::default() + } + + pub fn secondary_logger(mut self, logger: T) -> Self { + self.secondary_logger = Some(logger); + self + } + + fn build(self) -> TeaclaveLogger<T> { + let task_logger = RwLock::new(None); + + TeaclaveLogger { + task_logger, + secondary_logger: self.secondary_logger, + } + } + + pub fn init(self) { + // Two loggers may be used, so we set the level to trace, and filter inside function log. + log::set_max_level(LevelFilter::Trace); + + let logger = self.build(); + + log::set_boxed_logger(Box::new(logger)).unwrap(); + } +} + +impl<T> Default for Builder<T> { + fn default() -> Self { + Self { + secondary_logger: None, + } + } +} + +#[cfg(feature = "enclave_unit_test")] +pub mod tests { + use teaclave_test_utils::*; + + pub fn run_tests() -> bool { + run_tests!(test_log,) + } + + // The logs are not sent to the storage service as the service client is not configured in + // teaclave_unit_tests. + fn test_log() { + log::trace!(task_id = "dummy"; "you should not see this line"); + log::info!("you should see this line from the secondary logger"); + log::warn!(task_id = ""; ""); + } +} diff --git a/logger/src/task_logger.rs b/logger/src/task_logger.rs new file mode 100644 index 00000000..7720f9bc --- /dev/null +++ b/logger/src/task_logger.rs @@ -0,0 +1,62 @@ +// Licensed to the Apache Software Foundation (ASF) under one +// or more contributor license agreements. See the NOTICE file +// distributed with this work for additional information +// regarding copyright ownership. The ASF licenses this file +// to you under the Apache License, Version 2.0 (the +// "License"); you may not use this file except in compliance +// with the License. You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, +// software distributed under the License is distributed on an +// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY +// KIND, either express or implied. See the License for the +// specific language governing permissions and limitations +// under the License. + +use std::sync::{Arc, Mutex}; + +use log::{Metadata, Record}; + +pub struct TaskLogger { + buffer: Arc<Mutex<Vec<String>>>, +} + +impl TaskLogger { + pub fn new(addr: u64) -> Self { + let buffer = unsafe { Arc::from_raw(std::ptr::from_exposed_addr_mut(addr as usize)) }; + + Self { buffer } + } +} + +impl TaskLogger { + pub fn enabled(&self, _metadata: &Metadata) -> bool { + true + } + + pub fn log(&mut self, record: &Record) { + let metadata = record.metadata(); + + if !self.enabled(metadata) { + return; + } + + let mut output = format!("[{}", metadata.level()); + if let Some(module_path) = record.module_path() { + output += " "; + output += module_path; + } + let output = format!("{}] {}", output, record.args()); + self.buffer.lock().unwrap().push(output); + } + + pub fn flush(&mut self) {} +} + +impl Drop for TaskLogger { + fn drop(&mut self) { + self.flush() + } +} diff --git a/sdk/rust/src/bindings.rs b/sdk/rust/src/bindings.rs index 67d2c3ff..5b388ed3 100644 --- a/sdk/rust/src/bindings.rs +++ b/sdk/rust/src/bindings.rs @@ -371,7 +371,7 @@ pub unsafe extern "C" fn teaclave_get_task_result( let task_id = CStr::from_ptr(task_id).to_string_lossy().into_owned(); match client.get_task_result(&task_id) { - Ok(result) => { + Ok((result, _)) => { if *task_result_len < result.len() { return 1; } else { diff --git a/sdk/rust/src/lib.rs b/sdk/rust/src/lib.rs index 69c9f3a9..d4243a8c 100644 --- a/sdk/rust/src/lib.rs +++ b/sdk/rust/src/lib.rs @@ -495,7 +495,7 @@ impl FrontendClient { Ok(serialized_response) } - pub fn get_task_result(&mut self, task_id: &str) -> Result<Vec<u8>> { + pub fn get_task_result(&mut self, task_id: &str) -> Result<(Vec<u8>, Vec<String>)> { loop { let request = GetTaskRequest::new(task_id.try_into()?); let response = self.get_task_with_request(request)?; @@ -504,7 +504,7 @@ impl FrontendClient { std::thread::sleep(std::time::Duration::from_secs(1)); } TaskResult::Ok(task_outputs) => { - return Ok(task_outputs.return_value); + return Ok((task_outputs.return_value, task_outputs.log)); } TaskResult::Err(task_error) => { return Err(anyhow::anyhow!(task_error.reason)); @@ -610,8 +610,9 @@ mod tests { .unwrap(); let _ = client.invoke_task(&task_id).unwrap(); - let result = client.get_task_result(&task_id).unwrap(); - assert_eq!(result, b"Hello, Teaclave!") + let (result, log) = client.get_task_result(&task_id).unwrap(); + assert_eq!(result, b"Hello, Teaclave!"); + assert!(log.is_empty()); } #[test] diff --git a/services/execution/enclave/Cargo.toml b/services/execution/enclave/Cargo.toml index 99e6b8c8..a13bf0fc 100644 --- a/services/execution/enclave/Cargo.toml +++ b/services/execution/enclave/Cargo.toml @@ -45,7 +45,7 @@ cov = ["teaclave_service_enclave_utils/cov"] enclave_unit_test = ["teaclave_binder/enclave_unit_test", "teaclave_test_utils/mesalock_sgx"] [dependencies] -log = { version = "0.4.17", features = ["release_max_level_info"] } +log = { version = "0.4.17", features = ["release_max_level_info", "kv_unstable_std"] } anyhow = { version = "1.0.26" } serde_json = { version = "1.0.39" } serde = { version = "1.0.92", features = ["derive"] } diff --git a/services/execution/enclave/src/lib.rs b/services/execution/enclave/src/lib.rs index ee3e7772..e9d9ce6d 100644 --- a/services/execution/enclave/src/lib.rs +++ b/services/execution/enclave/src/lib.rs @@ -15,6 +15,8 @@ // specific language governing permissions and limitations // under the License. +#![feature(strict_provenance)] + extern crate sgx_types; use std::untrusted::path::PathEx; diff --git a/services/execution/enclave/src/service.rs b/services/execution/enclave/src/service.rs index 42a210ba..916b58c7 100644 --- a/services/execution/enclave/src/service.rs +++ b/services/execution/enclave/src/service.rs @@ -218,6 +218,19 @@ impl TeaclaveExecutionService { } fn invoke_task(task: &StagedTask, fusion_base: &PathBuf) -> Result<TaskOutputs> { + let save_log = task + .function_arguments + .get("save_log") + .ok() + .and_then(|v| v.as_str().and_then(|s| s.parse().ok())) + .unwrap_or(false); + let log_arc = Arc::new(Mutex::new(Vec::<String>::new())); + + if save_log { + let log_arc = Arc::into_raw(log_arc.clone()); + log::info!(buffer = log_arc.expose_addr(); ""); + } + let file_mgr = TaskFileManager::new( WORKER_BASE_DIR, fusion_base, @@ -232,7 +245,15 @@ fn invoke_task(task: &StagedTask, fusion_base: &PathBuf) -> Result<TaskOutputs> let summary = worker.invoke_function(invocation)?; let outputs_tag = finalize_task(&file_mgr)?; - let task_outputs = TaskOutputs::new(summary.as_bytes(), outputs_tag); + if save_log { + log::info!(buffer = 0; ""); + } + + let log = Arc::try_unwrap(log_arc) + .map_err(|_| anyhow::anyhow!("log buffer is referenced more than once"))? + .into_inner()?; + let task_outputs = TaskOutputs::new(summary.as_bytes(), outputs_tag, log); + Ok(task_outputs) } diff --git a/services/proto/src/proto/teaclave_common.proto b/services/proto/src/proto/teaclave_common.proto index 4a7e88ec..405d029f 100644 --- a/services/proto/src/proto/teaclave_common.proto +++ b/services/proto/src/proto/teaclave_common.proto @@ -35,6 +35,7 @@ message FileCryptoInfo { message TaskOutputs { bytes return_value = 1; map<string, bytes> tags_map = 2; + repeated string log = 3; } message TaskFailure { diff --git a/services/proto/src/teaclave_common.rs b/services/proto/src/teaclave_common.rs index 8c0aa799..c36ceaf1 100644 --- a/services/proto/src/teaclave_common.rs +++ b/services/proto/src/teaclave_common.rs @@ -134,6 +134,7 @@ impl std::convert::TryFrom<proto::TaskOutputs> for TaskOutputs { let ret = TaskOutputs { return_value: proto.return_value, tags_map: proto.tags_map.try_into()?, + log: proto.log, }; Ok(ret) } @@ -143,6 +144,7 @@ impl std::convert::From<TaskOutputs> for proto::TaskOutputs { proto::TaskOutputs { return_value: outputs.return_value, tags_map: outputs.tags_map.into(), + log: outputs.log, } } } diff --git a/services/utils/service_enclave_utils/Cargo.toml b/services/utils/service_enclave_utils/Cargo.toml index 1d54e0b8..53ba9f96 100644 --- a/services/utils/service_enclave_utils/Cargo.toml +++ b/services/utils/service_enclave_utils/Cargo.toml @@ -26,9 +26,6 @@ edition = "2021" [features] default = [] mesalock_sgx = [ - "env_logger/termcolor", - "env_logger/humantime", - "env_logger/regex", "teaclave_types/mesalock_sgx", "teaclave_attestation/mesalock_sgx", "teaclave_rpc/mesalock_sgx", @@ -40,11 +37,13 @@ anyhow = { version = "1.0.26" } env_logger = { version = "0.9.3", default_features = false } log = { version = "0.4.17", features = ["release_max_level_info"] } +teaclave_attestation = { path = "../../../attestation" } +teaclave_config = { path = "../../../config" } +teaclave_logger = { path = "../../../logger" } +teaclave_proto = { path = "../../proto" } +teaclave_rpc = { path = "../../../rpc" } teaclave_service_enclave_utils_proc_macro = { path = "./proc_macro" } -teaclave_types = { path = "../../../types" } -teaclave_attestation = { path = "../../../attestation" } -teaclave_rpc = { path = "../../../rpc" } -teaclave_config = { path = "../../../config" } +teaclave_types = { path = "../../../types" } -sgx_cov = { version = "2.0.0", optional = true } +sgx_cov = { version = "2.0.0", optional = true } sgx_macros = { version = "2.0.0", optional = true } diff --git a/services/utils/service_enclave_utils/src/lib.rs b/services/utils/service_enclave_utils/src/lib.rs index fe79224f..3be3e4bf 100644 --- a/services/utils/service_enclave_utils/src/lib.rs +++ b/services/utils/service_enclave_utils/src/lib.rs @@ -15,9 +15,12 @@ // specific language governing permissions and limitations // under the License. +#![feature(concat_idents)] + #[cfg(feature = "mesalock_sgx")] extern crate sgx_trts; +use anyhow::Result; use log::debug; use log::error; use std::backtrace; @@ -30,7 +33,7 @@ use teaclave_attestation::AttestedTlsConfig; use teaclave_config::RuntimeConfig; use teaclave_rpc::config::SgxTrustedTlsClientConfig; use teaclave_rpc::endpoint::Endpoint; -use teaclave_types::EnclaveInfo; +use teaclave_types::{EnclaveInfo, TeeServiceError, TeeServiceResult}; mod macros; @@ -49,24 +52,26 @@ extern "C" { pub struct ServiceEnclave; impl ServiceEnclave { - pub fn init(_name: &str) -> teaclave_types::TeeServiceResult<()> { - env_logger::init_from_env( - env_logger::Env::new() - .filter_or("TEACLAVE_LOG", "RUST_LOG") - .write_style_or("TEACLAVE_LOG_STYLE", "RUST_LOG_STYLE"), - ); + pub fn init(_name: &str) -> TeeServiceResult<()> { + let env = env_logger::Env::new() + .filter_or("TEACLAVE_LOG", "RUST_LOG") + .write_style_or("TEACLAVE_LOG_STYLE", "RUST_LOG_STYLE"); + let env_logger = env_logger::Builder::from_env(env).build(); + teaclave_logger::Builder::new() + .secondary_logger(env_logger) + .init(); debug!("Enclave initializing"); if backtrace::enable_backtrace(backtrace::PrintFormat::Full).is_err() { error!("Cannot enable backtrace"); - return Err(teaclave_types::TeeServiceError::SgxError); + return Err(TeeServiceError::SgxError); } Ok(()) } - pub fn finalize() -> teaclave_types::TeeServiceResult<()> { + pub fn finalize() -> TeeServiceResult<()> { debug!("Enclave finalizing"); unsafe { debug!("g_peak_heap_used: {}", g_peak_heap_used); @@ -80,15 +85,15 @@ impl ServiceEnclave { } } -pub fn base_dir_for_db(config: &RuntimeConfig) -> anyhow::Result<PathBuf> { +pub fn base_dir_for_db(config: &RuntimeConfig) -> Result<PathBuf> { base_dir(config, "database") } -pub fn base_dir_for_offload_functions(config: &RuntimeConfig) -> anyhow::Result<PathBuf> { +pub fn base_dir_for_offload_functions(config: &RuntimeConfig) -> Result<PathBuf> { base_dir(config, "functions") } -fn base_dir(config: &RuntimeConfig, sub_name: &str) -> anyhow::Result<PathBuf> { +fn base_dir(config: &RuntimeConfig, sub_name: &str) -> Result<PathBuf> { let fusion_base = config.mount.fusion_base_dir.as_path(); // We only create this base directory in test_mode // This directory should be mounted in release mode @@ -125,7 +130,7 @@ macro_rules! impl_create_trusted_endpoint_fn { as_root_ca_cert: &[u8], verifier: AttestationReportVerificationFn, attested_tls_config: Arc<RwLock<AttestedTlsConfig>>, - ) -> anyhow::Result<Endpoint> { + ) -> Result<Endpoint> { let service_enclave_attrs = enclave_info .get_enclave_attr($enclave_attr) .expect("enclave_info"); diff --git a/tests/functional/enclave/src/execution_service.rs b/tests/functional/enclave/src/execution_service.rs index e1b29f6d..f645f16f 100644 --- a/tests/functional/enclave/src/execution_service.rs +++ b/tests/functional/enclave/src/execution_service.rs @@ -39,7 +39,8 @@ fn test_execute_function() { .function_name("builtin-echo") .executor(Executor::Builtin) .function_arguments(hashmap!( - "message" => "Hello, Teaclave Tests!" + "message" => "Hello, Teaclave Tests!", + "save_log" => "true", )) .build(); @@ -57,8 +58,12 @@ fn test_execute_function() { let get_request = GetRequest::new(ts.key().as_slice()); let get_response = storage_client.get(get_request).unwrap(); let updated_task = TaskState::from_slice(get_response.value.as_slice()).unwrap(); + let result = updated_task.result.unwrap(); + assert_eq!(result.return_value, b"Hello, Teaclave Tests!"); + let info_log = result.log.iter().find(|l| l.contains("INFO")).unwrap(); + assert_eq!( - updated_task.result.unwrap().return_value, - b"Hello, Teaclave Tests!" + info_log, + "[INFO teaclave_function::echo] Hello, Teaclave Tests!" ); } diff --git a/tests/functional/enclave/src/scheduler_service.rs b/tests/functional/enclave/src/scheduler_service.rs index a08a3b34..e660490d 100644 --- a/tests/functional/enclave/src/scheduler_service.rs +++ b/tests/functional/enclave/src/scheduler_service.rs @@ -103,7 +103,7 @@ fn test_update_task_status_result() { let response = client.update_task_status(request); assert!(response.is_ok()); - let task_outputs = TaskOutputs::new("return value", hashmap!()); + let task_outputs = TaskOutputs::new("return value", hashmap!(), vec![]); let request = UpdateTaskResultRequest::new(task_id, Ok(task_outputs)); let response = client.update_task_result(request); diff --git a/tests/unit/enclave/Cargo.toml b/tests/unit/enclave/Cargo.toml index 40596af5..3eda321f 100644 --- a/tests/unit/enclave/Cargo.toml +++ b/tests/unit/enclave/Cargo.toml @@ -39,6 +39,8 @@ mesalock_sgx = [ "teaclave_types/enclave_unit_test", "teaclave_crypto/mesalock_sgx", "teaclave_crypto/enclave_unit_test", + "teaclave_logger/mesalock_sgx", + "teaclave_logger/enclave_unit_test", "teaclave_config/mesalock_sgx", "teaclave_access_control_service_enclave/mesalock_sgx", "teaclave_access_control_service_enclave/enclave_unit_test", @@ -98,6 +100,7 @@ teaclave_rpc = { path = "../../../rpc" } teaclave_service_enclave_utils = { path = "../../../services/utils/service_enclave_utils" } teaclave_types = { path = "../../../types" } teaclave_crypto = { path = "../../../crypto" } +teaclave_logger = { path = "../../../logger" } [target.'cfg(not(target_vendor = "teaclave"))'.dependencies] sgx_types = { version = "2.0.0" } diff --git a/tests/unit/enclave/src/lib.rs b/tests/unit/enclave/src/lib.rs index c904e0c4..b3bd4da7 100644 --- a/tests/unit/enclave/src/lib.rs +++ b/tests/unit/enclave/src/lib.rs @@ -43,6 +43,7 @@ fn handle_run_test(_: &RunTestInput) -> TeeServiceResult<RunTestOutput> { teaclave_types::tests::run_tests(), teaclave_crypto::tests::run_tests(), rusty_leveldb::tests::run_tests(), + teaclave_logger::tests::run_tests(), ); assert!(ret); diff --git a/types/src/task.rs b/types/src/task.rs index fea76ffe..17928877 100644 --- a/types/src/task.rs +++ b/types/src/task.rs @@ -213,13 +213,19 @@ impl std::iter::FromIterator<(String, FileAuthTag)> for OutputsTags { pub struct TaskOutputs { pub return_value: Vec<u8>, pub tags_map: OutputsTags, + pub log: Vec<String>, } impl TaskOutputs { - pub fn new(value: impl Into<Vec<u8>>, tags_map: HashMap<String, FileAuthTag>) -> Self { + pub fn new( + value: impl Into<Vec<u8>>, + tags_map: HashMap<String, FileAuthTag>, + log: Vec<String>, + ) -> Self { TaskOutputs { return_value: value.into(), tags_map: OutputsTags::new(tags_map), + log, } } } --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
