From 7b4c952888ae30c1663229dda857c636023e77e1 Mon Sep 17 00:00:00 2001 From: Bugen Zhao Date: Thu, 21 Dec 2023 13:36:35 +0800 Subject: [PATCH 1/4] show thread name in logs Signed-off-by: Bugen Zhao --- .../com/risingwave/tracing/TracingSlf4jImpl.java | 2 +- .../java/com/risingwave/java/binding/Binding.java | 3 ++- src/batch/src/task/task_manager.rs | 2 +- src/cmd_all/src/bin/risingwave.rs | 3 ++- src/connector/src/source/data_gen_util.rs | 2 +- src/frontend/src/session.rs | 2 +- src/jni_core/src/macros.rs | 6 +++++- src/jni_core/src/tracing_slf4j.rs | 5 +++++ .../src/hummock/compactor/compaction_executor.rs | 2 +- src/stream/src/task/stream_manager.rs | 2 +- src/utils/runtime/src/lib.rs | 2 +- src/utils/runtime/src/logger.rs | 12 +++++++++++- 12 files changed, 32 insertions(+), 11 deletions(-) diff --git a/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java b/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java index 0f87988ab57dc..150f74a95d3e5 100644 --- a/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java +++ b/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java @@ -27,6 +27,6 @@ public class TracingSlf4jImpl { public static final int TRACE = 4; public static void event(String name, int level, String message) { - Binding.tracingSlf4jEvent(name, level, message); + Binding.tracingSlf4jEvent(Thread.getCurrentThread().getName(), name, level, message); } } diff --git a/java/java-binding/src/main/java/com/risingwave/java/binding/Binding.java b/java/java-binding/src/main/java/com/risingwave/java/binding/Binding.java index 3001a180a15de..ff490982ccbd0 100644 --- a/java/java-binding/src/main/java/com/risingwave/java/binding/Binding.java +++ b/java/java-binding/src/main/java/com/risingwave/java/binding/Binding.java @@ -26,7 +26,8 @@ public class Binding { } } - public static native void tracingSlf4jEvent(String name, int level, String message); + public static native void tracingSlf4jEvent( + String threadName, String name, int level, String message); public static native int vnodeCount(); diff --git a/src/batch/src/task/task_manager.rs b/src/batch/src/task/task_manager.rs index b2f20ea6412a0..e24c9ee50b288 100644 --- a/src/batch/src/task/task_manager.rs +++ b/src/batch/src/task/task_manager.rs @@ -70,7 +70,7 @@ impl BatchManager { builder.worker_threads(worker_threads_num); } builder - .thread_name("risingwave-batch-tasks") + .thread_name("rw-batch") .enable_all() .build() .unwrap() diff --git a/src/cmd_all/src/bin/risingwave.rs b/src/cmd_all/src/bin/risingwave.rs index b7693c6fa06a2..44b55a38fd4ca 100644 --- a/src/cmd_all/src/bin/risingwave.rs +++ b/src/cmd_all/src/bin/risingwave.rs @@ -193,7 +193,8 @@ fn main() -> Result<()> { fn playground(opts: PlaygroundOpts) { let settings = risingwave_rt::LoggerSettings::new("playground") - .with_target("risingwave_storage", Level::WARN); + .with_target("risingwave_storage", Level::WARN) + .with_thread_name(true); risingwave_rt::init_risingwave_logger(settings); risingwave_rt::main_okk(risingwave_cmd_all::playground(opts)).unwrap(); } diff --git a/src/connector/src/source/data_gen_util.rs b/src/connector/src/source/data_gen_util.rs index 7d990cf0ff8c9..001a726f93018 100644 --- a/src/connector/src/source/data_gen_util.rs +++ b/src/connector/src/source/data_gen_util.rs @@ -31,7 +31,7 @@ pub fn spawn_data_generation_stream( ) -> impl Stream + Send + 'static { static RUNTIME: LazyLock = LazyLock::new(|| { tokio::runtime::Builder::new_multi_thread() - .thread_name("risingwave-data-generation") + .thread_name("rw-datagen") .enable_all() .build() .expect("failed to build data-generation runtime") diff --git a/src/frontend/src/session.rs b/src/frontend/src/session.rs index e68cb3ff80d28..ba786e2bb34a3 100644 --- a/src/frontend/src/session.rs +++ b/src/frontend/src/session.rs @@ -436,7 +436,7 @@ impl FrontendEnv { Arc::new(BackgroundShutdownRuntime::from( Builder::new_multi_thread() .worker_threads(4) - .thread_name("frontend-compute-threads") + .thread_name("rw-batch-local") .enable_all() .build() .unwrap(), diff --git a/src/jni_core/src/macros.rs b/src/jni_core/src/macros.rs index 89b10b98b9d4c..b5223e813d8a4 100644 --- a/src/jni_core/src/macros.rs +++ b/src/jni_core/src/macros.rs @@ -310,6 +310,10 @@ macro_rules! cast_jvalue { let obj = $value.l().expect("should be object"); unsafe { jni::objects::JByteArray::from_raw(obj.into_raw()) } }}; + ({ String }, $value:expr) => {{ + let obj = $value.l().expect("should be object"); + jni::objects::JString::from(obj) + }}; ({ $($class:tt)+ }, $value:expr) => {{ $value.l().expect("should be object") }}; @@ -442,7 +446,7 @@ macro_rules! for_all_plain_native_methods { ($macro:path $(,$args:tt)*) => { $macro! { { - public static native void tracingSlf4jEvent(String name, int level, String string); + public static native void tracingSlf4jEvent(String threadName, String name, int level, String string); public static native int vnodeCount(); diff --git a/src/jni_core/src/tracing_slf4j.rs b/src/jni_core/src/tracing_slf4j.rs index ce410b9bcb001..1cd07d1a8a81c 100644 --- a/src/jni_core/src/tracing_slf4j.rs +++ b/src/jni_core/src/tracing_slf4j.rs @@ -23,11 +23,15 @@ use crate::{execute_and_catch, EnvParam}; #[no_mangle] pub(crate) extern "system" fn Java_com_risingwave_java_binding_Binding_tracingSlf4jEvent( env: EnvParam<'_>, + thread_name: JString<'_>, class_name: JString<'_>, level: jint, message: JString<'_>, ) { execute_and_catch(env, move |env| { + let thread_name = env.get_string(&thread_name)?; + let thread_name: Cow<'_, str> = (&thread_name).into(); + let class_name = env.get_string(&class_name)?; let class_name: Cow<'_, str> = (&class_name).into(); @@ -39,6 +43,7 @@ pub(crate) extern "system" fn Java_com_risingwave_java_binding_Binding_tracingSl tracing::event!( target: "risingwave_connector_node", $lvl, + thread = thread_name.as_ref(), class = class_name.as_ref(), "{message}", ) diff --git a/src/storage/src/hummock/compactor/compaction_executor.rs b/src/storage/src/hummock/compactor/compaction_executor.rs index d3086709a33de..426245a89a392 100644 --- a/src/storage/src/hummock/compactor/compaction_executor.rs +++ b/src/storage/src/hummock/compactor/compaction_executor.rs @@ -30,7 +30,7 @@ impl CompactionExecutor { let mut worker_num = resource_util::cpu::total_cpu_available() as usize; let runtime = { let mut builder = tokio::runtime::Builder::new_multi_thread(); - builder.thread_name("risingwave-compaction"); + builder.thread_name("rw-compaction"); if let Some(worker_threads_num) = worker_threads_num { builder.worker_threads(worker_threads_num); worker_num = worker_threads_num; diff --git a/src/stream/src/task/stream_manager.rs b/src/stream/src/task/stream_manager.rs index 013873f17697e..579cb7810c49f 100644 --- a/src/stream/src/task/stream_manager.rs +++ b/src/stream/src/task/stream_manager.rs @@ -427,7 +427,7 @@ impl LocalStreamManagerCore { builder.worker_threads(worker_threads_num); } builder - .thread_name("risingwave-streaming-actor") + .thread_name("rw-streaming") .enable_all() .build() .unwrap() diff --git a/src/utils/runtime/src/lib.rs b/src/utils/runtime/src/lib.rs index 343550246e243..50577c8df1565 100644 --- a/src/utils/runtime/src/lib.rs +++ b/src/utils/runtime/src/lib.rs @@ -74,7 +74,7 @@ where } tokio::runtime::Builder::new_multi_thread() - .thread_name("risingwave-main") + .thread_name("rw-main") .enable_all() .build() .unwrap() diff --git a/src/utils/runtime/src/logger.rs b/src/utils/runtime/src/logger.rs index 18794b257f79f..990c62564316c 100644 --- a/src/utils/runtime/src/logger.rs +++ b/src/utils/runtime/src/logger.rs @@ -38,6 +38,8 @@ pub struct LoggerSettings { colorful: bool, /// Output to `stderr` instead of `stdout`. stderr: bool, + /// Whether to include thread name in the log. + with_thread_name: bool, /// Override target settings. targets: Vec<(String, tracing::metadata::LevelFilter)>, /// Override the default level. @@ -57,6 +59,7 @@ impl LoggerSettings { enable_tokio_console: false, colorful: console::colors_enabled_stderr() && console::colors_enabled(), stderr: false, + with_thread_name: true, // TODO: false targets: vec![], default_level: None, } @@ -74,6 +77,12 @@ impl LoggerSettings { self } + /// Whether to include thread name in the log. + pub fn with_thread_name(mut self, enabled: bool) -> Self { + self.with_thread_name = enabled; + self + } + /// Overrides the default target settings. pub fn with_target( mut self, @@ -210,6 +219,7 @@ pub fn init_risingwave_logger(settings: LoggerSettings) { // fmt layer (formatting and logging to `stdout` or `stderr`) { let fmt_layer = tracing_subscriber::fmt::layer() + .with_thread_names(settings.with_thread_name) .with_timer(default_timer.clone()) .with_ansi(settings.colorful) .with_writer(move || { @@ -359,7 +369,7 @@ pub fn init_risingwave_logger(settings: LoggerSettings) { let otel_tracer = { let runtime = tokio::runtime::Builder::new_multi_thread() .enable_all() - .thread_name("risingwave-otel") + .thread_name("rw-otel") .worker_threads(2) .build() .unwrap(); From 4b0d8cb74f6f8c1633a93fbf8bbddb84b42debf2 Mon Sep 17 00:00:00 2001 From: Bugen Zhao Date: Thu, 21 Dec 2023 14:04:54 +0800 Subject: [PATCH 2/4] fix thread name Signed-off-by: Bugen Zhao --- .../main/java/com/risingwave/tracing/TracingSlf4jImpl.java | 2 +- src/jni_core/src/tracing_slf4j.rs | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java b/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java index 150f74a95d3e5..9354a6043a56a 100644 --- a/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java +++ b/java/connector-node/tracing/src/main/java/com/risingwave/tracing/TracingSlf4jImpl.java @@ -27,6 +27,6 @@ public class TracingSlf4jImpl { public static final int TRACE = 4; public static void event(String name, int level, String message) { - Binding.tracingSlf4jEvent(Thread.getCurrentThread().getName(), name, level, message); + Binding.tracingSlf4jEvent(Thread.currentThread().getName(), name, level, message); } } diff --git a/src/jni_core/src/tracing_slf4j.rs b/src/jni_core/src/tracing_slf4j.rs index 1cd07d1a8a81c..8f7222d11c647 100644 --- a/src/jni_core/src/tracing_slf4j.rs +++ b/src/jni_core/src/tracing_slf4j.rs @@ -43,8 +43,8 @@ pub(crate) extern "system" fn Java_com_risingwave_java_binding_Binding_tracingSl tracing::event!( target: "risingwave_connector_node", $lvl, - thread = thread_name.as_ref(), - class = class_name.as_ref(), + thread = &*thread_name, + class = &*class_name, "{message}", ) }; From 43623e7e8a38d11377b6c9e9d589302337fdc527 Mon Sep 17 00:00:00 2001 From: Bugen Zhao Date: Thu, 21 Dec 2023 14:30:08 +0800 Subject: [PATCH 3/4] set default value Signed-off-by: Bugen Zhao --- src/cmd_all/src/bin/risingwave.rs | 3 ++- src/utils/runtime/src/logger.rs | 2 +- 2 files changed, 3 insertions(+), 2 deletions(-) diff --git a/src/cmd_all/src/bin/risingwave.rs b/src/cmd_all/src/bin/risingwave.rs index 44b55a38fd4ca..27d24096487bf 100644 --- a/src/cmd_all/src/bin/risingwave.rs +++ b/src/cmd_all/src/bin/risingwave.rs @@ -201,7 +201,8 @@ fn playground(opts: PlaygroundOpts) { fn standalone(opts: StandaloneOpts) { let settings = risingwave_rt::LoggerSettings::new("standalone") - .with_target("risingwave_storage", Level::WARN); + .with_target("risingwave_storage", Level::WARN) + .with_thread_name(true); risingwave_rt::init_risingwave_logger(settings); risingwave_rt::main_okk(risingwave_cmd_all::standalone(opts)).unwrap(); } diff --git a/src/utils/runtime/src/logger.rs b/src/utils/runtime/src/logger.rs index 990c62564316c..e8abb0aef65eb 100644 --- a/src/utils/runtime/src/logger.rs +++ b/src/utils/runtime/src/logger.rs @@ -59,7 +59,7 @@ impl LoggerSettings { enable_tokio_console: false, colorful: console::colors_enabled_stderr() && console::colors_enabled(), stderr: false, - with_thread_name: true, // TODO: false + with_thread_name: false, targets: vec![], default_level: None, } From d5a81841eef0939e632d1cc042728ed343960517 Mon Sep 17 00:00:00 2001 From: Bugen Zhao Date: Thu, 21 Dec 2023 20:02:06 +0800 Subject: [PATCH 4/4] fix unit test Signed-off-by: Bugen Zhao --- src/jni_core/src/macros.rs | 6 +----- 1 file changed, 1 insertion(+), 5 deletions(-) diff --git a/src/jni_core/src/macros.rs b/src/jni_core/src/macros.rs index b5223e813d8a4..97a9e60492844 100644 --- a/src/jni_core/src/macros.rs +++ b/src/jni_core/src/macros.rs @@ -310,10 +310,6 @@ macro_rules! cast_jvalue { let obj = $value.l().expect("should be object"); unsafe { jni::objects::JByteArray::from_raw(obj.into_raw()) } }}; - ({ String }, $value:expr) => {{ - let obj = $value.l().expect("should be object"); - jni::objects::JString::from(obj) - }}; ({ $($class:tt)+ }, $value:expr) => {{ $value.l().expect("should be object") }}; @@ -886,7 +882,7 @@ mod tests { // This test shows the signature of all native methods let expected = expect_test::expect![[r#" [ - tracingSlf4jEvent (Ljava/lang/String;ILjava/lang/String;)V, + tracingSlf4jEvent (Ljava/lang/String;Ljava/lang/String;ILjava/lang/String;)V, vnodeCount ()I, iteratorNewHummock ([B)J, iteratorNewStreamChunk (J)J,