diff --git a/Cargo.toml b/Cargo.toml index 3faa3991a1cadc3fa55827abd1f6ad8aeb61146f..0fae0f4d8e86bc61f865fbd330dd02f982c13334 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -4,5 +4,6 @@ members = [ "ylong_ffrt", "ylong_io", "ylong_runtime", - "ylong_runtime_macros" + "ylong_runtime_macros", + "ylong_tracing" ] \ No newline at end of file diff --git a/bundle.json b/bundle.json index 4e1033ef8a0799959b74a3d31117c4590d8129ec..8d9c616f32a679c04c8681ad30088141d7885b33 100644 --- a/bundle.json +++ b/bundle.json @@ -26,7 +26,8 @@ "ram": "~200KB", "deps": { "components": [ - "ffrt" + "ffrt", + "hilog" ], "third_party": [] }, @@ -41,6 +42,13 @@ "header_base": [], "header_files": [] } + }, + { + "name": "//commonlibrary/rust/ylong_runtime/ylong_tracing:ylong_tracing", + "header": { + "header_base": [], + "header_files": [] + } } ], "test": [ diff --git a/ylong_runtime/BUILD.gn b/ylong_runtime/BUILD.gn index 4d70614caaa12b56052d72cd7b8a5fae0461c912..1f6f96645183c77ccb5d2e9746a31352799ece50 100644 --- a/ylong_runtime/BUILD.gn +++ b/ylong_runtime/BUILD.gn @@ -26,6 +26,7 @@ ohos_rust_shared_library("ylong_runtime") { "net", "sync", "time", + "trace", ] sources = [ "src/lib.rs" ] @@ -33,5 +34,6 @@ ohos_rust_shared_library("ylong_runtime") { "../ylong_io:ylong_io", "../ylong_runtime_macros:ylong_runtime_macros(${host_toolchain})", "//third_party/rust/crates/libc:lib", + "//third_party/rust/crates/tracing/tracing:lib", ] } diff --git a/ylong_runtime/Cargo.toml b/ylong_runtime/Cargo.toml index c9d7083d1b1e6a01367c74da29428da94aee1368..448cdf8ed819ad83b6ae09e3d0e603ab96d7bf51 100644 --- a/ylong_runtime/Cargo.toml +++ b/ylong_runtime/Cargo.toml @@ -59,11 +59,16 @@ macros = ["ylong_runtime_macros"] # Metrics component metrics = [] +# Trace component +trace = ["tracing"] + [dependencies] libc = "0.2.134" ylong_io = { path = "../ylong_io", optional = true } ylong_ffrt = { path = "../ylong_ffrt", optional = true } ylong_runtime_macros = { path = "../ylong_runtime_macros", optional = true } +tracing = { version = "0.1.40", optional = true } +tracing-subscriber = "*" [dev-dependencies] tokio = { version = "1.25", features = ["full"] } diff --git a/ylong_runtime/src/executor/blocking_pool.rs b/ylong_runtime/src/executor/blocking_pool.rs index 43a38f10a0a2f1ff7f6c9f33948786ecfc842480..dea5afe0a1ef1f5d2e5d0e1501fd34535fea92bb 100644 --- a/ylong_runtime/src/executor/blocking_pool.rs +++ b/ylong_runtime/src/executor/blocking_pool.rs @@ -191,6 +191,7 @@ impl BlockPoolSpawner { Ok(()) } + #[track_caller] pub(crate) fn spawn_blocking(&self, builder: &TaskBuilder, task: T) -> JoinHandle where T: FnOnce() -> R, @@ -198,6 +199,9 @@ impl BlockPoolSpawner { R: Send + 'static, { let task = BlockingTask(Some(task)); + #[cfg(feature = "trace")] + let task = crate::trace::task(task); + let scheduler: Weak = Weak::new(); let (task, handle) = Task::create_task(builder, scheduler, task, VirtualTableType::Ylong); let _ = self.spawn(task); diff --git a/ylong_runtime/src/executor/mod.rs b/ylong_runtime/src/executor/mod.rs index 2a32904eb18221a66de48241a832cc56b0f5e7b9..f2c1caaf1becdc6a3c5df2b272cfb639be2bdb2d 100644 --- a/ylong_runtime/src/executor/mod.rs +++ b/ylong_runtime/src/executor/mod.rs @@ -180,6 +180,7 @@ impl Runtime { /// /// runtime.spawn(test_future(1)); /// ``` + #[track_caller] pub fn spawn(&self, task: T) -> JoinHandle where T: Future + Send + 'static, @@ -189,11 +190,15 @@ impl Runtime { } #[inline] + #[track_caller] pub(crate) fn spawn_with_attr(&self, task: T, builder: &TaskBuilder) -> JoinHandle where T: Future + Send + 'static, R: Send + 'static, { + #[cfg(feature = "trace")] + let task = crate::trace::task(task); + match &self.async_spawner { #[cfg(feature = "current_thread_runtime")] AsyncHandle::CurrentThread(current_thread) => current_thread.spawn(builder, task), @@ -226,6 +231,7 @@ impl Runtime { /// 10 /// }); /// ``` + #[track_caller] pub fn spawn_blocking(&self, task: T) -> JoinHandle where T: FnOnce() -> R + Send + 'static, @@ -263,6 +269,7 @@ impl Runtime { /// /// assert_eq!(result.unwrap(), 4); /// ``` + #[track_caller] pub fn block_on(&self, task: T) -> R where T: Future, @@ -278,6 +285,9 @@ impl Runtime { ctx.set(&cur_context as *const _ as *const ()); }); + #[cfg(feature = "trace")] + let task = crate::trace::task(task); + let ret = match &self.async_spawner { #[cfg(feature = "current_thread_runtime")] AsyncHandle::CurrentThread(current_thread) => current_thread.block_on(task), diff --git a/ylong_runtime/src/lib.rs b/ylong_runtime/src/lib.rs index 85d9e6292b26586fcb78a14c1b64743ae269fdb4..31d628dad7ad6f3830dff286b018fe84a01bdafb 100644 --- a/ylong_runtime/src/lib.rs +++ b/ylong_runtime/src/lib.rs @@ -77,3 +77,53 @@ cfg_fs! { cfg_net! { pub mod net; } + +cfg_trace! { + pub(crate) mod trace; +} + +mod test{ + use std::panic; + use std::time::Duration; + + #[test] + fn panic_test(){ + let subscriber = tracing_subscriber::fmt().with_max_level(tracing::Level::TRACE).finish(); + let _ = tracing::subscriber::set_global_default(subscriber); + // let a= std::thread::spawn(||{ + // panic::set_hook(Box::new(|info|{ + // tracing::debug!("panic happen {:?}", info); + // })); + // panic!("1111111111111"); + // panic::take_hook(); + // }); + // a.join(); + // panic!("1111111111111"); + + async fn sss() -> i32 { + let mutex = crate::sync::Mutex::new(1); + let a = mutex.lock().await; + crate::time::sleep(std::time::Duration::from_secs(1)).await; + drop(a); + let a = mutex.try_lock().unwrap(); + drop(a); + crate::block_on(async { + tracing::debug!("in sss()"); + }); + // todo!(); + // unreachable!(); + let a:Option = None; + a.unwrap(); + panic!("!!!!!!!!!!panic!!!!!!!!!!"); + #[allow(unreachable_code)] + 22122 + } + + let runtime = crate::spawn(sss()); + let _a = crate::block_on(runtime); + std::thread::sleep(Duration::from_secs(1)); + + // panic!("1111111111111111"); + // panic!("2222222222222222"); + } +} \ No newline at end of file diff --git a/ylong_runtime/src/macros.rs b/ylong_runtime/src/macros.rs index 8f7791921b7b1abffb3cc83ac248feacdee726ae..3c591a80b83a75aa345f395057422ef480c90408 100644 --- a/ylong_runtime/src/macros.rs +++ b/ylong_runtime/src/macros.rs @@ -98,3 +98,13 @@ macro_rules! cfg_metrics { )* } } + +macro_rules! cfg_trace { + ($($item:item)*) => { + $( + #[cfg(feature = "trace")] + #[cfg_attr(doc_cfg, doc(cfg(feature = "trace")))] + $item + )* + } +} diff --git a/ylong_runtime/src/spawn.rs b/ylong_runtime/src/spawn.rs index 6550d5ed42f149ce55f7af7979602abdc8c52146..ee035554f9d6e841682b1b7e1d31777e56f32011 100644 --- a/ylong_runtime/src/spawn.rs +++ b/ylong_runtime/src/spawn.rs @@ -18,6 +18,7 @@ use crate::task::join_handle::JoinHandle; use crate::task::TaskBuilder; /// Spawns a task on the blocking pool. +#[track_caller] pub(crate) fn spawn_blocking(builder: &TaskBuilder, task: T) -> JoinHandle where T: FnOnce() -> R, @@ -30,6 +31,7 @@ where /// Gets global default executor, spawns async tasks by the task builder, and /// returns. +#[track_caller] pub(crate) fn spawn_async(builder: &TaskBuilder, task: T) -> JoinHandle where T: Future, diff --git a/ylong_runtime/src/sync/mutex.rs b/ylong_runtime/src/sync/mutex.rs index 5cef03982430c8d4ad2e60fd3bf5563535bd9840..7b028e9425d7d967b53d2483e3e84b64e8bea6d6 100644 --- a/ylong_runtime/src/sync/mutex.rs +++ b/ylong_runtime/src/sync/mutex.rs @@ -33,6 +33,8 @@ use crate::sync::semaphore_inner::SemaphoreInner; /// When using across different futures, users need to wrap the mutex inside an /// Arc, just like the use of [`std::sync::Mutex`]. pub struct Mutex { + #[cfg(feature = "trace")] + span: tracing::Span, /// Semaphore to provide mutual exclusion sem: SemaphoreInner, /// The data protected by this mutex @@ -64,10 +66,29 @@ impl Mutex { /// /// let _a = Mutex::new(2); /// ``` + #[track_caller] pub fn new(t: T) -> Mutex { + #[cfg(feature = "trace")] + let span = { + let local = std::panic::Location::caller(); + let span = tracing::trace_span!( + parent: None, + "runtime.mutex", + file = local.file(), + line = local.line(), + column = local.column(), + ); + span.in_scope(|| { + tracing::debug!(target: "Mutex", "new"); + }); + span + }; + Mutex { sem: SemaphoreInner::new(1).unwrap(), data: UnsafeCell::new(t), + #[cfg(feature = "trace")] + span, } } } @@ -96,6 +117,15 @@ impl Mutex { // The result of `acquire()` will be `Err()` only when the semaphore is closed. // `Mutex` will not close, so the result of `acquire()` must be `Ok(())`. self.sem.acquire().await.unwrap(); + + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "Mutex", + "lock success", + ); + }); + MutexGuard(self) } @@ -121,8 +151,26 @@ impl Mutex { /// ``` pub fn try_lock(&self) -> Result, LockError> { match self.sem.try_acquire() { - Ok(_) => Ok(MutexGuard(self)), - Err(_) => Err(LockError), + Ok(_) => { + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "Mutex", + "try_lock success", + ); + }); + Ok(MutexGuard(self)) + } + Err(_) => { + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "Mutex", + "try_lock failure", + ); + }); + Err(LockError) + } } } @@ -144,6 +192,13 @@ impl MutexGuard<'_, T> { // Unlocks the mutex. Wakes the first future waiting for the mutex. fn unlock(&mut self) { self.0.sem.release(); + #[cfg(feature = "trace")] + self.0.span.in_scope(|| { + tracing::debug!( + target: "Mutex", + "unlock success", + ); + }); } } diff --git a/ylong_runtime/src/sync/rwlock.rs b/ylong_runtime/src/sync/rwlock.rs index ec09bdbe12ef61975741da4518499da21435fbbb..f4e5110fc9f7a45e9eef4c7303096ab0287463b5 100644 --- a/ylong_runtime/src/sync/rwlock.rs +++ b/ylong_runtime/src/sync/rwlock.rs @@ -54,6 +54,8 @@ const MAX_READS: i64 = i64::MAX >> 2; /// }); /// ``` pub struct RwLock { + #[cfg(feature = "trace")] + span: tracing::Span, read_sem: SemaphoreInner, write_sem: SemaphoreInner, write_mutex: SemaphoreInner, @@ -76,8 +78,26 @@ impl RwLock { /// /// let lock = RwLock::new(0); /// ``` + #[track_caller] pub fn new(t: T) -> RwLock { + #[cfg(feature = "trace")] + let span = { + let local = std::panic::Location::caller(); + let span = tracing::trace_span!( + parent: None, + "runtime.rwlock", + file = local.file(), + line = local.line(), + column = local.column(), + ); + span.in_scope(|| { + tracing::debug!(target: "RwLock", "new"); + }); + span + }; RwLock { + #[cfg(feature = "trace")] + span, read_sem: SemaphoreInner::new(0).unwrap(), write_sem: SemaphoreInner::new(0).unwrap(), write_mutex: SemaphoreInner::new(1).unwrap(), @@ -116,6 +136,15 @@ impl RwLock { // `RwLock` will not close, so the result of `acquire()` must be `Ok(())`. self.read_sem.acquire().await.unwrap(); } + + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "read success", + ); + }); + RwLockReadGuard(self) } @@ -136,6 +165,13 @@ impl RwLock { let mut read_count = self.read_count.load(Acquire); loop { if read_count < 0 { + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "try_read failure", + ); + }); return Err(LockError); } else { match self.read_count.compare_exchange_weak( @@ -145,6 +181,13 @@ impl RwLock { Acquire, ) { Ok(_) => { + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "try_read success", + ); + }); return Ok(RwLockReadGuard(self)); } Err(curr) => { @@ -183,6 +226,13 @@ impl RwLock { if read_count >= 0 && self.read_wait.fetch_add(read_count, Release) != -read_count { self.write_sem.acquire().await.unwrap(); } + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "write success", + ); + }); RwLockWriteGuard(self) } @@ -208,9 +258,25 @@ impl RwLock { .read_count .compare_exchange(0, -MAX_READS, AcqRel, Acquire) { - Ok(_) => Ok(RwLockWriteGuard(self)), + Ok(_) => { + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "try_write success", + ); + }); + Ok(RwLockWriteGuard(self)) + } Err(_) => { self.write_mutex.release(); + #[cfg(feature = "trace")] + self.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "try_write failure", + ); + }); Err(LockError) } } @@ -267,6 +333,13 @@ impl RwLockReadGuard<'_, T> { { self.0.write_sem.release(); } + #[cfg(feature = "trace")] + self.0.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "ReadGuard drop success", + ); + }); } } @@ -310,6 +383,13 @@ impl Drop for RwLockWriteGuard<'_, T> { let read_count = self.0.read_count.fetch_add(MAX_READS, Release) + MAX_READS; self.0.read_sem.release_multi(read_count as usize); self.0.write_mutex.release(); + #[cfg(feature = "trace")] + self.0.span.in_scope(|| { + tracing::debug!( + target: "RwLock", + "WriteGuard drop success", + ); + }); } } diff --git a/ylong_runtime/src/task/builder.rs b/ylong_runtime/src/task/builder.rs index 0159a6402467a5363971fafb5736105b94a61f8a..39e1852db696e717065fc8f16927da3b99b669d7 100644 --- a/ylong_runtime/src/task/builder.rs +++ b/ylong_runtime/src/task/builder.rs @@ -59,6 +59,7 @@ impl TaskBuilder { /// todo: for multiple-instance runtime, should provide a spawn_on /// Using the current task setting, spawns a task onto the global runtime. + #[track_caller] pub fn spawn(&self, task: T) -> JoinHandle where T: Future, @@ -69,6 +70,7 @@ impl TaskBuilder { } /// Using the current task setting, spawns a task onto the blocking pool. + #[track_caller] pub fn spawn_blocking(&self, task: T) -> JoinHandle where T: FnOnce() -> R, diff --git a/ylong_runtime/src/task/mod.rs b/ylong_runtime/src/task/mod.rs index e30e088382b5ad178f33f874921c25df265a7d9d..9bdcd8ab087bd40036c704aa688155b3732b5bef 100644 --- a/ylong_runtime/src/task/mod.rs +++ b/ylong_runtime/src/task/mod.rs @@ -136,6 +136,7 @@ impl Drop for Task { } /// Using the default task setting, spawns a task onto the global runtime. +#[track_caller] pub fn spawn(task: T) -> JoinHandle where T: Future, @@ -146,6 +147,7 @@ where } /// Using the default task setting, spawns a blocking task. +#[track_caller] pub fn spawn_blocking(task: T) -> JoinHandle where T: FnOnce() -> R, @@ -156,6 +158,7 @@ where } /// Blocks the current thread until the `Future` passed in is completed. +#[track_caller] pub fn block_on(task: T) -> T::Output where T: Future, diff --git a/ylong_runtime/src/task/task_handle.rs b/ylong_runtime/src/task/task_handle.rs index cdb60579820e5d8bc3c689c49d6909d9c6c04b62..643e433ab5f66d30d69f5a1b453d4c273cd9acf6 100644 --- a/ylong_runtime/src/task/task_handle.rs +++ b/ylong_runtime/src/task/task_handle.rs @@ -128,7 +128,13 @@ where _ => {} }, - Err(_) => { + Err(e) => { + if let Some(info) = e.downcast_ref::<&str>(){ + tracing::error!( + target: "runtime task panic", + "{info:?}", + ); + } let output = Err(ScheduleError::new(ErrorKind::Panic, "panic happen")); self.finish(cur, output); } diff --git a/ylong_runtime/src/time/sleep.rs b/ylong_runtime/src/time/sleep.rs index a096c849f835574b1992c22ab4bf59aaeaaadc01..50bb7f5c80566b525dfbcb6451a81974771c8caf 100644 --- a/ylong_runtime/src/time/sleep.rs +++ b/ylong_runtime/src/time/sleep.rs @@ -27,6 +27,7 @@ const TEN_YEARS: Duration = Duration::from_secs(86400 * 365 * 10); /// or ylong_runtime::block_on. The async wrapping is necessary since it makes /// the function become lazy in order to get successfully executed on the /// runtime. +#[track_caller] pub fn sleep_until(instant: Instant) -> Sleep { Sleep::new_timeout(instant) } @@ -39,6 +40,7 @@ pub fn sleep_until(instant: Instant) -> Sleep { /// or ylong_runtime::block_on. The async wrapping is necessary since it makes /// the function become lazy in order to get successfully executed on the /// runtime. +#[track_caller] pub fn sleep(duration: Duration) -> Sleep { // If the time reaches the maximum value, // then set the default timing time to 10 years. @@ -71,6 +73,9 @@ pub struct Sleep { deadline: Instant, inner: SleepInner, + + #[cfg(feature = "trace")] + span: tracing::Span, } cfg_ffrt!( @@ -91,14 +96,33 @@ cfg_ffrt!( impl Sleep { // Creates a Sleep structure based on the given deadline. + #[track_caller] fn new_timeout(deadline: Instant) -> Self { + #[cfg(feature = "trace")] + let span = { + let duration = (deadline - start_time).as_millis(); + let local = std::panic::Location::caller(); + let span = tracing::trace_span!( + parent: None, + "runtime.time", + file = local.file(), + line = local.line(), + column = local.column(), + ); + span.in_scope(|| { + tracing::debug!(target: "new_timeout", "{duration:?}ms"); + }); + span + }; Self { need_insert: true, deadline, inner: SleepInner { timer: None, waker: None, - } + }, + #[cfg(feature = "trace")] + span, } } @@ -133,6 +157,9 @@ cfg_ffrt!( fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll { let this = self.get_mut(); + #[cfg(feature = "trace")] + let _span = this.span.enter(); + if this.need_insert { if let Some(duration) = this.deadline.checked_duration_since(Instant::now()) { let ms = duration.as_millis() @@ -157,8 +184,12 @@ cfg_ffrt!( // this unwrap is safe since we have already insert the timer into the entry let timer = this.inner.timer.as_ref().unwrap(); if timer.result() { + #[cfg(feature = "trace")] + tracing::debug!(target: "new_timeout", "Ready"); Poll::Ready(()) } else { + #[cfg(feature = "trace")] + tracing::debug!(target: "new_timeout", "Pending"); Poll::Pending } } @@ -188,6 +219,7 @@ cfg_not_ffrt!( impl Sleep { // Creates a Sleep structure based on the given deadline. + #[track_caller] fn new_timeout(deadline: Instant) -> Self { let handle = Handle::get_handle().expect("sleep new out of worker ctx"); @@ -195,13 +227,32 @@ cfg_not_ffrt!( let deadline = cmp::max(deadline, start_time); let timer = Clock::new(); + + #[cfg(feature = "trace")] + let span = { + let duration = (deadline - start_time).as_millis(); + let local = std::panic::Location::caller(); + let span = tracing::trace_span!( + parent: None, + "runtime.time", + file = local.file(), + line = local.line(), + column = local.column(), + ); + span.in_scope(|| { + tracing::debug!(target: "new_timeout", "{duration:?}ms"); + }); + span + }; Self { need_insert: true, deadline, inner: SleepInner { timer, handle, - } + }, + #[cfg(feature = "trace")] + span, } } @@ -226,6 +277,9 @@ cfg_not_ffrt!( let this = self.get_mut(); let driver = &this.inner.handle; + #[cfg(feature = "trace")] + let _span = this.span.enter(); + if this.need_insert { let ms = this .deadline @@ -249,8 +303,12 @@ cfg_not_ffrt!( } if this.inner.timer.result() { + #[cfg(feature = "trace")] + tracing::debug!(target: "new_timeout", "Ready"); Poll::Ready(()) } else { + #[cfg(feature = "trace")] + tracing::debug!(target: "new_timeout", "Pending"); Poll::Pending } } diff --git a/ylong_runtime/src/trace.rs b/ylong_runtime/src/trace.rs new file mode 100644 index 0000000000000000000000000000000000000000..ebaf1033c9b4900f1507e115462326a7ab20fbbd --- /dev/null +++ b/ylong_runtime/src/trace.rs @@ -0,0 +1,15 @@ +use tracing::Instrument; +pub(crate) use tracing::instrument::Instrumented; + +#[track_caller] +pub(crate) fn task(task: T) -> Instrumented { + let local = std::panic::Location::caller(); + let span = tracing::trace_span!( + target: "ylong::task", + "runtime.spawn", + file = local.file(), + line = local.line(), + column = local.column(), + ); + task.instrument(span) +} \ No newline at end of file diff --git a/ylong_tracing/BUILD.gn b/ylong_tracing/BUILD.gn new file mode 100644 index 0000000000000000000000000000000000000000..411a948ae153c751e67df765d5cb93c04272efb2 --- /dev/null +++ b/ylong_tracing/BUILD.gn @@ -0,0 +1,32 @@ +# Copyright (c) 2023 Huawei Device Co., Ltd. +# Licensed 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. + +import("//build/ohos.gni") +import("//build/test.gni") + +ohos_rust_shared_library("ylong_tracing") { + part_name = "ylong_runtime" + subsystem_name = "commonlibrary" + + crate_name = "ylong_tracing" + edition = "2021" + + features = [ "hilog" ] + + sources = [ "src/lib.rs" ] + external_deps = [ "hilog:hilog_rust" ] + deps = [ + "//third_party/rust/crates/tracing/tracing:lib", + "//third_party/rust/crates/tracing/tracing-core:lib", + ] +} diff --git a/ylong_tracing/Cargo.toml b/ylong_tracing/Cargo.toml new file mode 100644 index 0000000000000000000000000000000000000000..e8b2ce0412d76d02ce358efb0057f1f54cbfed58 --- /dev/null +++ b/ylong_tracing/Cargo.toml @@ -0,0 +1,19 @@ +[package] +name = "ylong_tracing" +version = "0.1.0" +edition = "2021" +description = "Tracing for async usage" +license = "Apache-2.0" +repository = "https://gitee.com/openharmony/commonlibrary_rust_ylong_runtime" +keywords = ["ylong", "tracing", "hilog"] + +[features] +default = ["hilog"] +hilog = [] + +[dependencies] +tracing = { version = "0.1.37" } +tracing-core = { version = "0.1.31" } + +[dev-dependencies] +ylong_runtime = { path = "../ylong_runtime", features = ["time"] } diff --git a/ylong_tracing/src/lib.rs b/ylong_tracing/src/lib.rs new file mode 100644 index 0000000000000000000000000000000000000000..3963d16ca59b02bc2d2eccaa8304323c7b29d571 --- /dev/null +++ b/ylong_tracing/src/lib.rs @@ -0,0 +1,23 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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. + +//! # ylong_tracing +//! A subscriber for tracing, using hilog implementation at the bottom. + +mod registry; +mod span; +mod subscriber; +mod util; +mod visitor; + +pub use subscriber::HilogTracing; diff --git a/ylong_tracing/src/registry.rs b/ylong_tracing/src/registry.rs new file mode 100644 index 0000000000000000000000000000000000000000..a038e118dbe5ddb5ff9a5c4f28a8cdd4ceb812d6 --- /dev/null +++ b/ylong_tracing/src/registry.rs @@ -0,0 +1,116 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::cell::RefCell; +use std::sync::{Arc, Mutex}; + +use tracing_core::span::Id; + +use crate::span::SpanData; +use crate::util::{Pool, ThreadLocal}; + +#[derive(Debug)] +pub struct Registry { + span_pool: Pool, + current_spans: ThreadLocal>, +} + +impl Registry { + pub(crate) fn new() -> Registry { + Registry { + span_pool: Pool::new(), + current_spans: ThreadLocal::new(), + } + } + + pub(crate) fn get_current_spans(&self) -> &ThreadLocal> { + &self.current_spans + } + + pub(crate) fn pool_push(&self, data: SpanData) -> Id { + let id = self.span_pool.push(data); + usize_to_id(id) + } + + pub(crate) fn pool_get(&self, id: &Id) -> Arc> { + self.span_pool.get(id_to_usize(id)) + } + + pub(crate) fn pool_try_remove(&self, id: Id) -> bool { + self.span_pool.try_remove(id_to_usize(&id)) + } +} + +#[inline] +fn usize_to_id(i: usize) -> Id { + Id::from_u64(i as u64 + 1) +} + +#[inline] +fn id_to_usize(id: &Id) -> usize { + id.into_u64() as usize - 1 +} + +#[derive(Debug, Default)] +pub(crate) struct IdStack { + pub(crate) vec: Vec, +} + +impl IdStack { + pub(crate) fn push(&mut self, new_id: Id) -> bool { + let mut new_is_duplicate = false; + for id_group in self.vec.iter() { + if id_group.id == new_id { + new_is_duplicate = true; + break; + } + } + self.vec.push(IdGroup { + id: new_id, + is_duplicate: new_is_duplicate, + }); + !new_is_duplicate + } + + pub(crate) fn pop(&mut self, id: &Id) -> bool { + if let Some((i, _)) = self + .vec + .iter() + .enumerate() + .rev() + .find(|(_, id_group)| id_group.id == *id) + { + let remove_id_group = self.vec.remove(i); + return !remove_id_group.is_duplicate; + }; + false + } + + pub(crate) fn iter(&self) -> impl Iterator { + self.vec.iter().rev().filter_map( + |IdGroup { id, is_duplicate }| { + if !*is_duplicate { + Some(id) + } else { + None + } + }, + ) + } +} + +#[derive(Debug)] +pub(crate) struct IdGroup { + id: Id, + is_duplicate: bool, +} diff --git a/ylong_tracing/src/span.rs b/ylong_tracing/src/span.rs new file mode 100644 index 0000000000000000000000000000000000000000..147124a6c214412bfbd7072ddbd869f863187f68 --- /dev/null +++ b/ylong_tracing/src/span.rs @@ -0,0 +1,65 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::atomic::{AtomicUsize, Ordering}; + +use tracing_core::span::Id; +use tracing_core::Metadata; + +/// Store data about span +#[derive(Debug)] +pub(crate) struct SpanData { + /// span's metadata + metadata: &'static Metadata<'static>, + /// span's parent; if is root, parent is None + parent: Option, + /// span's fields and values + values: String, + /// this span's ref count + ref_count: AtomicUsize, +} + +impl SpanData { + pub(crate) fn new(metadata: &'static Metadata, values: String, parent: Option) -> Self { + SpanData { + metadata, + values, + parent, + ref_count: AtomicUsize::new(1), + } + } + + pub(crate) fn metadata(&self) -> &'static Metadata<'static> { + self.metadata + } + + pub(crate) fn parent(&self) -> &Option { + &self.parent + } + + pub(crate) fn values(&self) -> &String { + &self.values + } + + pub(crate) fn mut_values(&mut self) -> &mut String { + &mut self.values + } + + pub(crate) fn add_ref(&self) { + self.ref_count.fetch_add(1, Ordering::Relaxed); + } + + pub(crate) fn sub_ref(&self) -> usize { + self.ref_count.fetch_sub(1, Ordering::Relaxed) + } +} diff --git a/ylong_tracing/src/subscriber.rs b/ylong_tracing/src/subscriber.rs new file mode 100644 index 0000000000000000000000000000000000000000..20fb6a31d02ce183b309d1ddd468c415b3e41dc4 --- /dev/null +++ b/ylong_tracing/src/subscriber.rs @@ -0,0 +1,389 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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. + +#[cfg(feature = "hilog")] +use std::ffi::{c_char, CString}; +use std::fmt::{Debug, Write as _}; +use std::fs::File; +use std::io::Write as _; +use std::sync::{Arc, Mutex}; + +#[cfg(feature = "hilog")] +extern crate hilog_rust; + +#[cfg(feature = "hilog")] +use hilog_rust::*; +use tracing::level_filters::LevelFilter; +use tracing::span::{Attributes, Record}; +use tracing::subscriber::Interest; +use tracing::{Event, Id, Metadata, Subscriber}; +use tracing_core::span::Current; +#[cfg(feature = "hilog")] +use tracing_core::Level; + +use crate::registry::Registry; +use crate::span::SpanData; +use crate::util::DateTime; +use crate::visitor::StringVisitor; + +/// HilogTracing for tracing, using hilog implementation at the bottom. +#[derive(Debug)] +pub struct HilogTracing { + #[cfg(feature = "hilog")] + hilog_label: hilog_rust::HiLogLabel, + max_level_hint: Option, + registry: Registry, + file: Option>>, +} + +#[cfg(not(feature = "hilog"))] +impl Default for HilogTracing { + fn default() -> Self { + Self::new() + } +} + +impl HilogTracing { + /// Creates a new HilogTracing, log_type/domain/tag are used in hilog. + /// + /// # Example + /// + /// ```no_run + /// use hilog_rust::LogType; + /// use tracing::subscriber; + /// use ylong_tracing::HilogTracing; + /// + /// let subscriber = HilogTracing::new(LogType::LogCore, 0xd003200, "testTag"); + /// subscriber::set_global_default(subscriber).expect("set_global_default fail!"); + /// ``` + #[cfg(feature = "hilog")] + pub fn new(log_type: hilog_rust::LogType, domain: u32, tag: &'static str) -> Self { + let hilog_label = hilog_rust::HiLogLabel { + log_type, + domain, + tag, + }; + HilogTracing { + hilog_label, + max_level_hint: None, + registry: Registry::new(), + file: None, + } + } + + /// Creates a new HilogTracing, log_type/domain/tag are used in hilog. + /// + /// # Example + /// + /// ```no_run + /// use tracing::subscriber; + /// use ylong_tracing::HilogTracing; + /// + /// let subscriber = HilogTracing::new(); + /// subscriber::set_global_default(subscriber).expect("set_global_default fail!"); + /// ``` + #[cfg(not(feature = "hilog"))] + pub fn new() -> Self { + HilogTracing { + max_level_hint: None, + registry: Registry::new(), + file: None, + } + } + + /// Sets the max level of this Subscriber + /// + /// # Example + /// + /// ```no_run + /// use tracing::{subscriber, Level}; + /// use ylong_tracing::HilogTracing; + /// + /// #[cfg(feature = "hilog")] + /// let subscriber = HilogTracing::new(hilog_rust::LogType::LogCore, 0xd003200, "testTag") + /// .max_level_hint(Level::INFO); + /// + /// #[cfg(not(feature = "hilog"))] + /// let subscriber = HilogTracing::new().max_level_hint(Level::INFO); + /// + /// subscriber::set_global_default(subscriber).expect("set_global_default fail!"); + /// ``` + pub fn max_level_hint(self, filter: impl Into) -> Self { + let max_level_hint = Some(filter.into()); + HilogTracing { + #[cfg(feature = "hilog")] + hilog_label: self.hilog_label, + max_level_hint, + registry: self.registry, + file: self.file, + } + } + + /// Sets the file path of this Subscriber, it will be output to this file. + /// If file_path is `""`, this will not output to file. + /// + /// # Example + /// + /// ```no_run + /// use tracing::{subscriber, Level}; + /// use ylong_tracing::HilogTracing; + /// + /// #[cfg(feature = "hilog")] + /// let subscriber = HilogTracing::new(hilog_rust::LogType::LogCore, 0xd003200, "testTag") + /// .file_path("D:/log.log"); + /// + /// #[cfg(not(feature = "hilog"))] + /// let subscriber = HilogTracing::new().file_path("D:/log.log"); + /// + /// subscriber::set_global_default(subscriber).expect("set_global_default fail!"); + /// ``` + pub fn file_path(self, file_path: &'static str) -> Self { + let file = File::create(file_path).unwrap(); + + HilogTracing { + #[cfg(feature = "hilog")] + hilog_label: self.hilog_label, + max_level_hint: self.max_level_hint, + registry: self.registry, + file: Some(Arc::new(Mutex::new(file))), + } + } + + /// Gets event including span + fn get_event(&self, event: &Event<'_>) -> String { + let mut str_event = String::new(); + let mut visitor = StringVisitor::new(&mut str_event); + event.record(&mut visitor); + if let Err(e) = visitor.finish() { + panic!("event.string error happened:{:?}", e); + } + + str_event.insert_str(0, self.get_span(event).as_str()); + str_event + } + + /// Gets span + fn get_span(&self, event: &Event<'_>) -> String { + let parent = event.parent(); + let mut next = match parent { + Some(id) => Some(id.clone()), + None => { + if let Some(id_stack) = self.registry.get_current_spans().get() { + id_stack.borrow().iter().next().cloned() + } else { + None + } + } + }; + let mut str_span = String::new(); + let mut is_loop = false; + while let Some(id) = next { + is_loop = true; + + let mutex_span = self.registry.pool_get(&id); + let span = mutex_span.lock().unwrap(); + let mut curr_span = String::new(); + + write!(curr_span, "{}", span.metadata().name()).unwrap(); + + if !span.values().is_empty() { + write!(curr_span, "{{{}}}", span.values()).unwrap(); + } + + write!(curr_span, ":").unwrap(); + + str_span.insert_str(0, curr_span.as_str()); + next = span.parent().clone(); + } + + if is_loop { + str_span.write_char(' ').unwrap(); + } + + // write target + write!(str_span, "{}: ", event.metadata().target()).unwrap(); + + str_span + } + + #[cfg(feature = "hilog")] + fn clone_label(&self) -> HiLogLabel { + #[allow(clippy::needless_match)] + let log_type = match self.hilog_label.log_type { + LogType::LogApp => LogType::LogApp, + LogType::LogInit => LogType::LogInit, + LogType::LogCore => LogType::LogCore, + LogType::LogKmsg => LogType::LogKmsg, + LogType::LogTypeMax => LogType::LogTypeMax, + }; + HiLogLabel { + log_type, + domain: self.hilog_label.domain, + tag: self.hilog_label.tag, + } + } +} + +impl Subscriber for HilogTracing { + /// Occurs when a new callsite (span or event) is created. When the return + /// value is `always`, it indicates that the callsite must occur; When + /// 'never' indicates that the callsite never occur; Sometimes indicates + /// that the callsite needs to be re-evaluated with enable(). + fn register_callsite(&self, _metadata: &'static Metadata<'static>) -> Interest { + Interest::always() + } + + /// When a new callsite occurs, if the register_callsite() returns + /// `sometimes`, enter this method. + fn enabled(&self, _metadata: &Metadata<'_>) -> bool { + true + } + + /// Sets the highest level for this subscriber record, with the highest + /// efficiency. + fn max_level_hint(&self) -> Option { + self.max_level_hint + } + + /// Occurs when creating a new span, returns the ID of that span, so you can + /// customize whether two `spans` are equal. The ID will be stored in + /// Span::Inner::Id. The parent-child relationship between spans is + /// determined here + fn new_span(&self, span: &Attributes<'_>) -> Id { + let parent = if span.is_root() { + None + } else if span.is_contextual() { + self.current_span().id().map(|id| self.clone_span(id)) + } else { + span.parent().map(|id| self.clone_span(id)) + }; + + let mut str_span = String::new(); + let mut visitor = StringVisitor::new(&mut str_span); + span.values().record(&mut visitor); + if let Err(e) = visitor.finish() { + panic!("span.values error happened:{:?}", e); + } + + let span_data = SpanData::new(span.metadata(), str_span, parent); + self.registry.pool_push(span_data) + } + + /// Occurs when span.record() is called to add fields to span. + fn record(&self, id: &Id, values: &Record<'_>) { + let mutex_span = self.registry.pool_get(id); + let mut span = mutex_span.lock().unwrap(); + + let str_record = span.mut_values(); + let mut visitor = StringVisitor::new(str_record); + values.record(&mut visitor); + if let Err(e) = visitor.finish() { + panic!("span.record error happened:{:?}", e); + } + } + + fn record_follows_from(&self, _span: &Id, _follows: &Id) {} + + /// Whether to record this event, if it has been filtered by + /// `max_level_hint` will not enter this method + fn event_enabled(&self, _event: &Event<'_>) -> bool { + true + } + + /// Occurs when an event occurs, specifically implemented here + fn event(&self, event: &Event<'_>) { + let level = event.metadata().level(); + let str_message = self.get_event(event); + + if let Some(file) = &self.file { + let now = std::time::SystemTime::now(); + let datetime = DateTime::time_to_datetime(now); + + let mut file = file.lock().unwrap(); + writeln!(file, "{} {:5} {}", datetime, level, str_message).unwrap(); + } + + // call hilog + #[cfg(feature = "hilog")] + { + let log_label = self.clone_label(); + match *level { + // hilog currently does not support trace level logging + Level::TRACE => {} + Level::DEBUG => { + hilog_rust::debug!(log_label, "{}", str_message.as_str()); + } + Level::INFO => { + hilog_rust::info!(log_label, "{}", str_message.as_str()); + } + Level::WARN => { + hilog_rust::warn!(log_label, "{}", str_message.as_str()); + } + Level::ERROR => { + hilog_rust::error!(log_label, "{}", str_message.as_str()); + } + }; + } + } + + /// Occurs when a span enters. + fn enter(&self, id: &Id) { + if self + .registry + .get_current_spans() + .get_or_default() + .borrow_mut() + .push(id.clone()) + { + self.clone_span(id); + } + } + + /// Occurs when a span exits. + fn exit(&self, id: &Id) { + if let Some(spans) = self.registry.get_current_spans().get() { + if spans.borrow_mut().pop(id) { + self.try_close(id.clone()); + } + }; + } + + /// Occurs when span clone occurs, returns the ID of the new span. + fn clone_span(&self, id: &Id) -> Id { + let mutex_span = self.registry.pool_get(id); + let span = mutex_span.lock().unwrap(); + span.add_ref(); + id.clone() + } + + /// Occurs when span clone occurs, this method is called when span exit + /// occurs + fn try_close(&self, id: Id) -> bool { + self.registry.pool_try_remove(id) + } + + /// Current span of this thread. + fn current_span(&self) -> Current { + self.registry + .get_current_spans() + .get() + .and_then(|spans| { + let spans = spans.borrow(); + let id = spans.iter().next()?; + let mutex_span = self.registry.pool_get(id); + let span = mutex_span.lock().unwrap(); + Some(Current::new(id.clone(), span.metadata())) + }) + .unwrap_or_else(Current::none) + } +} diff --git a/ylong_tracing/src/util/mod.rs b/ylong_tracing/src/util/mod.rs new file mode 100644 index 0000000000000000000000000000000000000000..d5620da0444bf4db6d82c9c3e16b6a760275b242 --- /dev/null +++ b/ylong_tracing/src/util/mod.rs @@ -0,0 +1,21 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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. + +mod pool; +pub(crate) use pool::Pool; + +mod thread_local; +pub(crate) use thread_local::ThreadLocal; + +mod time; +pub(crate) use time::DateTime; diff --git a/ylong_tracing/src/util/pool.rs b/ylong_tracing/src/util/pool.rs new file mode 100644 index 0000000000000000000000000000000000000000..f7a7a137acf74c7551090091caf7e4b9298130d6 --- /dev/null +++ b/ylong_tracing/src/util/pool.rs @@ -0,0 +1,87 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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 crate::span::SpanData; + +#[cfg(target_pointer_width = "64")] +const VEC_SIZE: usize = 4096; +#[cfg(target_pointer_width = "32")] +const VEC_SIZE: usize = 128; + +#[derive(Debug)] +pub(crate) struct Pool { + vec: Arc>>>, +} + +#[derive(Debug, Clone)] +struct Entry { + data: Arc>, +} + +impl Pool { + pub(crate) fn new() -> Self { + let mut vec = Vec::with_capacity(VEC_SIZE); + for _ in 0..VEC_SIZE { + vec.push(None); + } + Pool { + vec: Arc::new(Mutex::new(vec)), + } + } + + pub(crate) fn push(&self, data: SpanData) -> usize { + let mut vec = self.vec.lock().unwrap(); + for i in 0..vec.len() { + let data_i = vec.get(i).unwrap(); + if data_i.is_none() { + vec[i] = Some(Entry { + data: Arc::new(Mutex::new(data)), + }); + return i; + } + } + vec.push(Some(Entry { + data: Arc::new(Mutex::new(data)), + })); + vec.len() - 1 + } + + pub(crate) fn get(&self, id: usize) -> Arc> { + let vec = self.vec.lock().unwrap(); + match vec.get(id).unwrap() { + None => panic!("invalid id"), + Some(span) => span.data.clone(), + } + } + + pub(crate) fn try_remove(&self, id: usize) -> bool { + let mut vec = self.vec.lock().unwrap(); + let mutex_span = match vec.get(id).unwrap() { + None => panic!("invalid id"), + Some(span) => span.clone(), + }; + let span = mutex_span.data.lock().unwrap(); + let ref_count = span.sub_ref(); + drop(span); + if ref_count == 1 { + if let Some(a) = vec.get_mut(id) { + *a = None; + } + true + } else { + false + } + } +} diff --git a/ylong_tracing/src/util/thread_local.rs b/ylong_tracing/src/util/thread_local.rs new file mode 100644 index 0000000000000000000000000000000000000000..beb1d5463f9ce942a2d273c41ff884cc70c7ebc4 --- /dev/null +++ b/ylong_tracing/src/util/thread_local.rs @@ -0,0 +1,239 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::cell::{Cell, UnsafeCell}; +use std::fmt::{Debug, Formatter}; +use std::mem::MaybeUninit; +use std::panic::UnwindSafe; +use std::slice::from_raw_parts_mut; +use std::sync::atomic::{AtomicBool, AtomicPtr, AtomicUsize, Ordering}; +use std::sync::Mutex; +use std::{mem, ptr}; + +const DEFAULT_THREAD: usize = 1; + +#[cfg(target_pointer_width = "32")] +const POINT_WIDTH: u8 = 32; +#[cfg(target_pointer_width = "64")] +const POINT_WIDTH: u8 = 64; + +const BUCKET_COUNT: usize = (POINT_WIDTH + 1) as usize; + +pub(crate) struct ThreadLocal { + buckets: [AtomicPtr>; BUCKET_COUNT], +} + +impl Debug for ThreadLocal { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + write!(f, "ThreadLocal {{ data: {:?} }}", self.get()) + } +} + +unsafe impl Sync for ThreadLocal {} + +impl UnwindSafe for ThreadLocal {} + +impl ThreadLocal { + pub(crate) fn new() -> ThreadLocal { + let initial = usize::from(POINT_WIDTH) - (DEFAULT_THREAD.leading_zeros() as usize) + 1; + let mut buckets = [ptr::null_mut(); BUCKET_COUNT]; + let mut size = 1; + for (i, bucket) in buckets[..initial].iter_mut().enumerate() { + *bucket = allocate_bucket::(size); + + if i != 0 { + size <<= 1; + } + } + ThreadLocal { + buckets: unsafe { mem::transmute(buckets) }, + } + } + + pub(crate) fn get(&self) -> Option<&T> { + self.get_inner(get_current_thread()) + } + + fn get_inner(&self, thread: Thread) -> Option<&T> { + let ptr = unsafe { self.buckets.get_unchecked(thread.bucket) }.load(Ordering::Acquire); + if ptr.is_null() { + None + } else { + unsafe { + let inner = &*ptr.add(thread.offset); + // only this thread can read + if (&inner.current as *const _ as *const bool).read() { + Some(&*(*inner.data.get()).as_ptr()) + } else { + None + } + } + } + } + + fn initial(&self, data: T) -> &T { + let thread = get_current_thread(); + let atomic_ptr = unsafe { self.buckets.get_unchecked(thread.bucket) }; + let mut ptr: *const _ = atomic_ptr.load(Ordering::Acquire); + + if ptr.is_null() { + let new_ptr = allocate_bucket(thread.bucket_len); + + match atomic_ptr.compare_exchange( + ptr::null_mut(), + new_ptr, + Ordering::AcqRel, + Ordering::Acquire, + ) { + Ok(_) => ptr = new_ptr, + Err(old_ptr) => { + unsafe { deallocate_bucket(new_ptr, thread.bucket_len) }; + ptr = old_ptr; + } + } + } + + let inner = unsafe { &*ptr.add(thread.offset) }; + let entry_data = inner.data.get(); + unsafe { entry_data.write(MaybeUninit::new(data)) }; + inner.current.store(true, Ordering::Release); + + unsafe { &*(*entry_data).as_ptr() } + } +} + +impl ThreadLocal { + pub(crate) fn get_or_default(&self) -> &T { + if let Some(value) = self.get_inner(get_current_thread()) { + value + } else { + self.initial(Default::default()) + } + } +} + +impl Drop for ThreadLocal { + fn drop(&mut self) { + let mut size = 1; + for (i, bucket) in self.buckets.iter_mut().enumerate() { + let tmp_size = size; + if i != 0 { + size <<= 1; + } + + let ptr = *bucket.get_mut(); + if !ptr.is_null() { + unsafe { deallocate_bucket(ptr, tmp_size) }; + } + } + } +} + +struct Inner { + current: AtomicBool, + data: UnsafeCell>, +} + +impl Drop for Inner { + fn drop(&mut self) { + if *self.current.get_mut() { + unsafe { + ptr::drop_in_place((*self.data.get()).as_mut_ptr()); + } + } + } +} + +fn allocate_bucket(size: usize) -> *mut Inner { + Box::into_raw( + (0..size) + .map(|_| Inner:: { + current: AtomicBool::new(false), + data: UnsafeCell::new(MaybeUninit::uninit()), + }) + .collect(), + ) as *mut _ +} + +unsafe fn deallocate_bucket(bucket: *mut Inner, size: usize) { + let _ = Box::from_raw(from_raw_parts_mut(bucket, size)); +} + +#[derive(Copy, Clone)] +struct Thread { + id: usize, + bucket: usize, + bucket_len: usize, + offset: usize, +} + +impl Thread { + fn new(id: usize) -> Thread { + let bucket = usize::from(POINT_WIDTH) - id.leading_zeros() as usize; + let bucket_size = 1 << bucket.saturating_sub(1); + let offset = if id != 0 { id ^ bucket_size } else { 0 }; + + Thread { + id, + bucket, + bucket_len: bucket_size, + offset, + } + } +} + +thread_local! { static THREAD: Cell> = const { Cell::new(None)}; } +thread_local! { static GUARD: Guard = const { Guard { id: Cell::new(0) } }; } + +static THREAD_ID: AtomicUsize = AtomicUsize::new(0); +/// Thread ID which is free +static THREAD_ID_HEAP: Mutex> = Mutex::new(Vec::new()); + +fn get_min_id() -> Option { + let mut vec_id = THREAD_ID_HEAP.lock().unwrap(); + if let Some((index, _)) = vec_id.iter().enumerate().min() { + Some(vec_id.remove(index)) + } else { + None + } +} + +struct Guard { + id: Cell, +} + +impl Drop for Guard { + fn drop(&mut self) { + let _ = THREAD.try_with(|thread| thread.set(None)); + // push drop thread id into HEAP + THREAD_ID_HEAP.lock().unwrap().push(self.id.get()); + } +} + +fn get_current_thread() -> Thread { + THREAD.with(|thread| match thread.get() { + Some(thread) => thread, + None => { + let new_id = if let Some(id) = get_min_id() { + id + } else { + THREAD_ID.fetch_add(1, Ordering::AcqRel) + }; + let new_thread = Thread::new(new_id); + thread.set(Some(new_thread)); + GUARD.with(|guard| guard.id.set(new_thread.id)); + + new_thread + } + }) +} diff --git a/ylong_tracing/src/util/time.rs b/ylong_tracing/src/util/time.rs new file mode 100644 index 0000000000000000000000000000000000000000..72c9672ed80b2c5fb772e5b7939d519eff09f28c --- /dev/null +++ b/ylong_tracing/src/util/time.rs @@ -0,0 +1,112 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::fmt::{Display, Formatter}; +use std::time::{SystemTime, UNIX_EPOCH}; + +pub(crate) struct DateTime { + year: i32, + month: u8, + day: u8, + hour: u8, + minute: u8, + second: u8, + nanos: u32, +} + +impl Display for DateTime { + fn fmt(&self, f: &mut Formatter<'_>) -> std::fmt::Result { + write!( + f, + "{:04}-{:02}-{:02} {:02}:{:02}:{:02}.{:06}", + self.year, + self.month, + self.day, + self.hour, + self.minute, + self.second, + self.nanos / 1000, + ) + } +} + +impl DateTime { + pub(crate) fn time_to_datetime(timestamp: SystemTime) -> DateTime { + let (second, nanos) = match timestamp.duration_since(UNIX_EPOCH) { + Ok(d) => (d.as_secs(), d.subsec_nanos()), + Err(_) => panic!("System Time can't be earlier than \"1970-01-01 00:00:00 UTC\""), + }; + + const SECOND_IN_DAY: u64 = 24 * 60 * 60; + const DAY_PER_400Y: u64 = 365 * 400 + 97; + const DAY_PER_100Y: u64 = 365 * 100 + 24; + const DAY_PER_4Y: u64 = 365 * 4 + 1; + const DAYS_IN_MONTH: [u8; 12] = [31, 30, 31, 30, 31, 31, 30, 31, 30, 31, 31, 29]; + // timestamp from 2000-03-01. + const TIMESTAMP_2000_MARCH: u64 = 946_684_800 + SECOND_IN_DAY * (31 + 29); + + let days = second / SECOND_IN_DAY - TIMESTAMP_2000_MARCH / SECOND_IN_DAY; + let remains_second = second % SECOND_IN_DAY; + + let cyc_400y_days = days / DAY_PER_400Y; + let mut remains_days = days % DAY_PER_400Y; + + let mut cyc_100y_days = remains_days / DAY_PER_100Y; + if cyc_100y_days == 4 { + cyc_100y_days -= 1; + } + remains_days -= cyc_100y_days * DAY_PER_100Y; + + let mut cyc_4y_days = remains_days / DAY_PER_4Y; + if cyc_4y_days == 25 { + cyc_4y_days -= 1; + } + remains_days -= cyc_4y_days * DAY_PER_4Y; + + let mut remains_years = remains_days / 365; + if remains_years == 4 { + remains_years -= 1; + } + remains_days -= remains_years * 365; + + let mut years = remains_years + 4 * cyc_4y_days + 100 * cyc_100y_days + 400 * cyc_400y_days; + let mut months: u8 = 0; + while u64::from(DAYS_IN_MONTH[months as usize]) <= remains_days { + remains_days -= DAYS_IN_MONTH[months as usize] as u64; + months += 1; + } + + months += 3; + if months >= 13 { + months -= 12; + years += 1; + } + + let mut hour = (remains_second / 3600) as u8; + hour += 8; + if hour >= 24 { + remains_days += 1; + hour %= 24; + } + + DateTime { + year: years as i32 + 2000, + month: months, + day: remains_days as u8 + 1, + hour, + minute: (remains_second / 60 % 60) as u8, + second: (remains_second % 60) as u8, + nanos, + } + } +} diff --git a/ylong_tracing/src/visitor.rs b/ylong_tracing/src/visitor.rs new file mode 100644 index 0000000000000000000000000000000000000000..834a33d826a00eeb5b5d9cdf5965460e0724be1e --- /dev/null +++ b/ylong_tracing/src/visitor.rs @@ -0,0 +1,54 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::fmt; +use std::fmt::{Debug, Write}; + +use tracing_core::field::Visit; +use tracing_core::Field; + +pub struct StringVisitor<'a> { + string: &'a mut String, + result: fmt::Result, +} + +impl<'a> StringVisitor<'a> { + pub(crate) fn new(string: &'a mut String) -> StringVisitor<'a> { + StringVisitor { + string, + result: Ok(()), + } + } + + fn write_padding(&mut self, value: &impl Debug) { + let padding = if self.string.is_empty() { "" } else { ", " }; + self.result = write!(self.string, "{}{:?}", padding, value) + } + + pub(crate) fn finish(self) -> fmt::Result { + self.result + } +} + +impl Visit for StringVisitor<'_> { + fn record_debug(&mut self, field: &Field, value: &dyn Debug) { + if self.result.is_err() { + return; + } + if field.name() == "message" { + self.write_padding(&format_args!("{:?}", value)); + } else { + self.write_padding(&format_args!("{}={:?}", field, value)); + } + } +} diff --git a/ylong_tracing/tests/async_usage.rs b/ylong_tracing/tests/async_usage.rs new file mode 100644 index 0000000000000000000000000000000000000000..6cf824b5905bd442ce47ff8b539bcfe919b33319 --- /dev/null +++ b/ylong_tracing/tests/async_usage.rs @@ -0,0 +1,60 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::fs::OpenOptions; +use std::io::Read; + +use tracing::{instrument, Level}; + +#[instrument] +async fn my_async_function1() { + ylong_runtime::time::sleep(std::time::Duration::from_millis(50)).await; + tracing::error!("something happened in my_async_function1()!"); +} + +/// SDV test for async usage +#[test] +fn async_usage() { + let path = "log3.log"; + let subscriber = ylong_tracing::HilogTracing::new() + .max_level_hint(Level::TRACE) + .file_path(path); + tracing::subscriber::set_global_default(subscriber).unwrap(); + + let handle = ylong_runtime::spawn(my_async_function1()); + + for _ in 0..100 { + ylong_runtime::spawn(async move { + ylong_runtime::time::sleep(std::time::Duration::from_millis(10)).await; + tracing::info!("normal sleep!"); + }); + } + + ylong_runtime::block_on(handle).unwrap(); + + let mut file = OpenOptions::new().read(true).open(path).unwrap(); + let mut res = String::new(); + file.read_to_string(&mut res).unwrap(); + std::fs::remove_file(path).unwrap(); + + for event in res.split('\n') { + if event.is_empty() { + break; + } + if event[27..31].to_string() == "INFO" { + assert_eq!("INFO async_usage: normal sleep!", event[27..].to_string()); + } else { + assert_eq!("ERROR my_async_function1: async_usage: something happened in my_async_function1()!", event[27..].to_string()); + } + } +} diff --git a/ylong_tracing/tests/basic.rs b/ylong_tracing/tests/basic.rs new file mode 100644 index 0000000000000000000000000000000000000000..bebbb1e7a135b2c73e310bd398b5e3585633ba07 --- /dev/null +++ b/ylong_tracing/tests/basic.rs @@ -0,0 +1,49 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::fs::OpenOptions; +use std::io::Read; + +use tracing::{event, instrument, Level}; + +#[instrument] +fn fun1(_i: usize, _j: i32) { + let data = (42, "forty-two"); + let private_data = "private"; + let error = "a bad error"; + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + "App warning: {}", + error + ); +} + +/// SDV test for instrument usage +#[test] +fn basic() { + let path = "log1.log"; + let subscriber = ylong_tracing::HilogTracing::new().file_path(path); + let _guard = tracing::subscriber::set_default(subscriber); + + fun1(0, 1); + + let mut file = OpenOptions::new().read(true).open(path).unwrap(); + let mut res = String::new(); + file.read_to_string(&mut res).unwrap(); + std::fs::remove_file(path).unwrap(); + + assert_eq!("WARN fun1{_i=0, _j=1}: app_events: App warning: a bad error, private_data=\"private\", data=(42, \"forty-two\")\n", res[27..].to_string()); +} diff --git a/ylong_tracing/tests/max_level.rs b/ylong_tracing/tests/max_level.rs new file mode 100644 index 0000000000000000000000000000000000000000..b613481ae071c82a77f13c42b0648115715b9895 --- /dev/null +++ b/ylong_tracing/tests/max_level.rs @@ -0,0 +1,51 @@ +// Copyright (c) 2023 Huawei Device Co., Ltd. +// Licensed 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::fs::OpenOptions; +use std::io::Read; + +use tracing::{event, instrument, Level}; + +#[instrument] +fn fun1(_i: usize, _j: i32) { + let data = (42, "forty-two"); + let private_data = "private"; + let error = "a bad error"; + event!( + target: "app_events", + Level::WARN, + private_data, + ?data, + "App warning: {}", + error + ); +} + +/// SDV test for max_level_hint() usage +#[test] +fn max_level() { + let path = "log2.log"; + let subscriber = ylong_tracing::HilogTracing::new() + .file_path(path) + .max_level_hint(Level::ERROR); + let _default = tracing::subscriber::set_default(subscriber); + + fun1(0, 1); + + let mut file = OpenOptions::new().read(true).open(path).unwrap(); + let mut res = String::new(); + file.read_to_string(&mut res).unwrap(); + std::fs::remove_file(path).unwrap(); + + assert!(res.is_empty()); +}