From 5a4b495a251b0cbc129279403c9a30c9b22d126c Mon Sep 17 00:00:00 2001 From: Bjorn Beishline <75190918+BjornTheProgrammer@users.noreply.github.com> Date: Thu, 12 Feb 2026 12:04:33 -0700 Subject: [PATCH] use tracing for logging instead This will temporarily break logging as Pumpkin logging for plugins is broken currently --- .../org/patchbukkit/PatchBukkitServer.java | 44 ++++++++++++++++++- proto/patchbukkit/bridge.proto | 3 ++ proto/patchbukkit/log.proto | 25 +++++++++++ rust/Cargo.lock | 1 + rust/Cargo.toml | 2 +- rust/src/events/handler.rs | 4 +- rust/src/java/jar.rs | 4 +- rust/src/java/jvm/worker.rs | 10 ++--- rust/src/java/native_callbacks/events.rs | 6 +-- rust/src/java/native_callbacks/log.rs | 19 ++++++++ rust/src/java/native_callbacks/mod.rs | 3 ++ rust/src/java/native_callbacks/sound.rs | 2 +- rust/src/java/plugin/command_manager.rs | 6 +-- rust/src/java/plugin/manager.rs | 18 ++++---- rust/src/java/resources.rs | 12 ++--- rust/src/lib.rs | 18 ++++---- rust/src/proto/mod.rs | 4 ++ 17 files changed, 139 insertions(+), 42 deletions(-) create mode 100644 proto/patchbukkit/log.proto create mode 100644 rust/src/java/native_callbacks/log.rs diff --git a/java/patchbukkit/src/main/java/org/patchbukkit/PatchBukkitServer.java b/java/patchbukkit/src/main/java/org/patchbukkit/PatchBukkitServer.java index a982154..ab631d2 100644 --- a/java/patchbukkit/src/main/java/org/patchbukkit/PatchBukkitServer.java +++ b/java/patchbukkit/src/main/java/org/patchbukkit/PatchBukkitServer.java @@ -19,6 +19,7 @@ import java.util.Map; import java.util.Set; import java.util.UUID; import java.util.function.Consumer; +import java.util.logging.Level; import java.util.logging.Logger; import net.kyori.adventure.audience.Audience; import net.kyori.adventure.key.Key; @@ -89,6 +90,9 @@ import org.patchbukkit.command.PatchBukkitCommandMap; import org.patchbukkit.command.PatchBukkitConsoleCommandSender; import org.patchbukkit.events.PatchBukkitEventManager; import org.patchbukkit.scheduler.PatchBukkitScheduler; +import patchbukkit.bridge.NativeBridgeFfi; +import patchbukkit.log.LogLevel; +import patchbukkit.log.SendLogRequest; @SuppressWarnings("removal") public class PatchBukkitServer implements Server { @@ -104,7 +108,45 @@ public class PatchBukkitServer implements Server { private final Map onlinePlayers = new java.util.concurrent.ConcurrentHashMap<>(); private final Map onlinePlayersByName = new java.util.concurrent.ConcurrentHashMap<>(); - private final Logger logger = Logger.getLogger("Minecraft"); + private static final Logger logger = Logger.getLogger("Minecraft"); + + static { + configureRootLogger(); + } + + private static final Map LEVEL_MAP = Map.of( + Level.SEVERE, LogLevel.SEVERE, + Level.WARNING, LogLevel.WARNING, + Level.INFO, LogLevel.INFO, + Level.CONFIG, LogLevel.CONFIG, + Level.FINE, LogLevel.FINE, + Level.FINER, LogLevel.FINER, + Level.FINEST, LogLevel.FINEST + ); + + private static void configureRootLogger() { + Logger root = Logger.getLogger(""); + root.setUseParentHandlers(false); + for (java.util.logging.Handler h : root.getHandlers()) { + root.removeHandler(h); + } + root.setLevel(Level.ALL); // accept everything, let your Rust side filter + root.addHandler(new java.util.logging.Handler() { + @Override + public void publish(java.util.logging.LogRecord record) { + LogLevel logLevel = LEVEL_MAP.getOrDefault(record.getLevel(), LogLevel.INFO); + NativeBridgeFfi.sendLog( + SendLogRequest.newBuilder() + .setLevel(logLevel) + .setMessage(record.getMessage()) + .setLoggerName(record.getLoggerName()) + .build() + ); + } + @Override public void flush() {} + @Override public void close() {} + }); + } /** * Called from Rust when a player joins the Pumpkin server diff --git a/proto/patchbukkit/bridge.proto b/proto/patchbukkit/bridge.proto index 5338248..09a774c 100644 --- a/proto/patchbukkit/bridge.proto +++ b/proto/patchbukkit/bridge.proto @@ -6,6 +6,7 @@ import "google/protobuf/wrappers.proto"; import "patchbukkit/abilities.proto"; import "patchbukkit/common/types.proto"; import "patchbukkit/events/event.proto"; +import "patchbukkit/log.proto"; import "patchbukkit/message.proto"; import "patchbukkit/registry.proto"; import "patchbukkit/sound.proto"; @@ -25,4 +26,6 @@ service NativeBridge { rpc PlayerEntityPlaySound(patchbukkit.sound.PlayerEntityPlaySoundRequest) returns (google.protobuf.Empty); rpc PlayerPlaySound(patchbukkit.sound.PlayerPlaySoundRequest) returns (google.protobuf.Empty); + + rpc SendLog(patchbukkit.log.SendLogRequest) returns (google.protobuf.Empty); } diff --git a/proto/patchbukkit/log.proto b/proto/patchbukkit/log.proto new file mode 100644 index 0000000..ea8aa40 --- /dev/null +++ b/proto/patchbukkit/log.proto @@ -0,0 +1,25 @@ +syntax = "proto3"; + +package patchbukkit.log; + +import "patchbukkit/common/types.proto"; + +option java_multiple_files = true; +option java_package = "patchbukkit.log"; + +enum LogLevel { + CONFIG = 0; + FINE = 1; + FINER = 2; + FINEST = 3; + INFO = 4; + OFF = 5; + SEVERE = 6; + WARNING = 7; +} + +message SendLogRequest { + LogLevel level = 1; + string logger_name = 2; + string message = 3; +} diff --git a/rust/Cargo.lock b/rust/Cargo.lock index 30e04d9..6fe3265 100644 --- a/rust/Cargo.lock +++ b/rust/Cargo.lock @@ -1911,6 +1911,7 @@ dependencies = [ "serde-saphyr", "serde_json", "tokio", + "tracing", "uuid", "walkdir", "zip", diff --git a/rust/Cargo.toml b/rust/Cargo.toml index 955182a..a376882 100644 --- a/rust/Cargo.toml +++ b/rust/Cargo.toml @@ -16,7 +16,7 @@ pumpkin-util = { git = "https://github.com/Pumpkin-MC/Pumpkin.git", branch = "ma pumpkin-api-macros = { git = "https://github.com/Pumpkin-MC/Pumpkin.git", branch = "master", package = "pumpkin-api-macros" } tokio = "1" -log = "0.4" +tracing = "0.1" glob = "0.3.3" j4rs = { version = "0.24" } rust-embed = { version = "8.11.0", features = ["interpolate-folder-path"] } diff --git a/rust/src/events/handler.rs b/rust/src/events/handler.rs index b41e374..6705e20 100644 --- a/rust/src/events/handler.rs +++ b/rust/src/events/handler.rs @@ -97,7 +97,7 @@ where }) .await { - log::error!("Failed to send event to JVM worker: {e}"); + tracing::error!("Failed to send event to JVM worker: {e}"); return; } @@ -107,7 +107,7 @@ where event.apply_modifications(server, response.data.unwrap().data.unwrap()); } Err(_) => { - log::warn!("JVM worker dropped response channel for event"); + tracing::warn!("JVM worker dropped response channel for event"); } } }) diff --git a/rust/src/java/jar.rs b/rust/src/java/jar.rs index df4602f..f94134e 100644 --- a/rust/src/java/jar.rs +++ b/rust/src/java/jar.rs @@ -17,10 +17,10 @@ pub fn discover_jar_files(plugin_folder: &Path) -> impl Iterator .expect("Invalid glob pattern") .filter_map(|entry| { entry - .map_err(|e| log::error!("Glob error: {e:?}")) + .map_err(|e| tracing::error!("Glob error: {e:?}")) .ok()? .canonicalize() - .map_err(|e| log::error!("Canonicalize error: {e:?}")) + .map_err(|e| tracing::error!("Canonicalize error: {e:?}")) .ok() }) } diff --git a/rust/src/java/jvm/worker.rs b/rust/src/java/jvm/worker.rs index 2878519..9ba9af8 100644 --- a/rust/src/java/jvm/worker.rs +++ b/rust/src/java/jvm/worker.rs @@ -39,7 +39,7 @@ impl JvmWorker { } pub async fn attach_thread(mut self) { - log::info!("JVM worker thread started"); + tracing::info!("JVM worker thread started"); while let Some(command) = self.command_rx.recv().await { match command { @@ -152,7 +152,7 @@ impl JvmWorker { let cancelled = match self.event_manager.fire_event(jvm, payload, plugin) { Ok(c) => c, Err(e) => { - log::error!("Failed to fire event: {e}"); + tracing::error!("Failed to fire event: {e}"); FireEventResponse { cancelled: false, data: Some(original_event), @@ -201,11 +201,11 @@ impl JvmWorker { } } - log::info!("JVM worker thread exited"); + tracing::info!("JVM worker thread exited"); } fn initialize_jvm(&mut self, j4rs_path: &PathBuf) -> anyhow::Result<()> { - log::info!("Initializing JVM with path: {j4rs_path:?}"); + tracing::info!("Initializing JVM with path: {j4rs_path:?}"); let jvm = JvmBuilder::new().with_base_path(j4rs_path).build()?; @@ -215,7 +215,7 @@ impl JvmWorker { self.jvm = Some(jvm); - log::info!("JVM initialized successfully"); + tracing::info!("JVM initialized successfully"); Ok(()) } } diff --git a/rust/src/java/native_callbacks/events.rs b/rust/src/java/native_callbacks/events.rs index 3b5fa28..d71e36d 100644 --- a/rust/src/java/native_callbacks/events.rs +++ b/rust/src/java/native_callbacks/events.rs @@ -21,7 +21,7 @@ pub fn ffi_native_bridge_register_event_impl(request: RegisterEventRequest) -> O _ => EventPriority::Highest, }; - log::info!( + tracing::info!( "Plugin '{}' registering listener for '{}' (priority={:?}, blocking={})", request.plugin_name, request.event_type, @@ -51,7 +51,7 @@ pub fn ffi_native_bridge_register_event_impl(request: RegisterEventRequest) -> O .await; } _ => { - log::warn!( + tracing::warn!( "Unsupported Bukkit event type '{}' from plugin '{}'", request.event_type, request.plugin_name ); @@ -66,7 +66,7 @@ pub fn ffi_native_bridge_register_event_impl(request: RegisterEventRequest) -> O pub fn ffi_native_bridge_call_event_impl(request: CallEventRequest) -> Option { let ctx = CALLBACK_CONTEXT.get()?; let event = request.event?; - log::debug!("Java calling event {:?}", event); + tracing::debug!("Java calling event {:?}", event); let context = ctx.plugin_context.clone(); diff --git a/rust/src/java/native_callbacks/log.rs b/rust/src/java/native_callbacks/log.rs new file mode 100644 index 0000000..1938d65 --- /dev/null +++ b/rust/src/java/native_callbacks/log.rs @@ -0,0 +1,19 @@ +use crate::proto::patchbukkit::log::{LogLevel, SendLogRequest}; + +pub fn ffi_native_bridge_send_log_impl(request: SendLogRequest) -> Option<()> { + let logger = &request.logger_name; + let msg = &request.message; + + match request.level() { + LogLevel::Severe => tracing::error!(logger = %logger, "{}", msg), + LogLevel::Warning => tracing::warn!(logger = %logger, "{}", msg), + LogLevel::Info => tracing::info!(logger = %logger, "{}", msg), + LogLevel::Config => tracing::debug!(logger = %logger, "{}", msg), + LogLevel::Fine => tracing::debug!(logger = %logger, "{}", msg), + LogLevel::Finer => tracing::trace!(logger = %logger, "{}", msg), + LogLevel::Finest => tracing::trace!(logger = %logger, "{}", msg), + LogLevel::Off => {} + } + + Some(()) +} diff --git a/rust/src/java/native_callbacks/mod.rs b/rust/src/java/native_callbacks/mod.rs index dc65f60..f843fe3 100644 --- a/rust/src/java/native_callbacks/mod.rs +++ b/rust/src/java/native_callbacks/mod.rs @@ -27,6 +27,9 @@ pub use sound::*; pub mod utils; +pub mod log; +pub use log::*; + static CALLBACK_CONTEXT: OnceLock = OnceLock::new(); struct CallbackContext { diff --git a/rust/src/java/native_callbacks/sound.rs b/rust/src/java/native_callbacks/sound.rs index 4ee229b..869a025 100644 --- a/rust/src/java/native_callbacks/sound.rs +++ b/rust/src/java/native_callbacks/sound.rs @@ -12,7 +12,7 @@ use crate::{ pub fn ffi_native_bridge_player_entity_play_sound_impl( request: PlayerEntityPlaySoundRequest, ) -> Option<()> { - log::error!("PlayerEntityPlaySoundRequest sent"); + tracing::error!("PlayerEntityPlaySoundRequest sent"); let ctx = CALLBACK_CONTEXT.get()?; let player_uuid = uuid::Uuid::parse_str(&request.player_uuid?.value).ok()?; let entity_uuid = uuid::Uuid::parse_str(&request.entity_uuid?.value).ok()?; diff --git a/rust/src/java/plugin/command_manager.rs b/rust/src/java/plugin/command_manager.rs index d96a8c5..dc14cd0 100644 --- a/rust/src/java/plugin/command_manager.rs +++ b/rust/src/java/plugin/command_manager.rs @@ -57,7 +57,7 @@ impl CommandManager { match self.try_tab_complete(jvm, sender, full_command, location) { Ok(suggestions) => Ok(suggestions), Err(e) => { - log::warn!("Tab completion failed: {e}"); + tracing::warn!("Tab completion failed: {e}"); Ok(None) } } @@ -168,7 +168,7 @@ impl CommandManager { "create", &[InvocationArg::try_from(&cmd_name)?, j_plugin_arg], )?)); - log::info!("Registering Bukkit command: {}", &cmd_name); + tracing::info!("Registering Bukkit command: {}", &cmd_name); { let cmd_lock = j_plugin_cmd.lock().unwrap(); let j_plugin_cmd_owned = jvm.clone_instance(&cmd_lock)?; @@ -240,7 +240,7 @@ impl CommandManager { let handled: bool = jvm.to_rust(dispatch_result)?; if !handled { - //log::warn!("Command was not handled by any Java plugin: {}", cmd_name); + //tracing::warn!("Command was not handled by any Java plugin: {}", cmd_name); } Ok(()) diff --git a/rust/src/java/plugin/manager.rs b/rust/src/java/plugin/manager.rs index 24eeae1..8754934 100644 --- a/rust/src/java/plugin/manager.rs +++ b/rust/src/java/plugin/manager.rs @@ -103,7 +103,7 @@ impl PluginManager { pub fn add_plugin(&mut self, plugin: Plugin) { let key = normalize_name(&plugin.name); if self.plugins.contains_key(&key) { - log::warn!( + tracing::warn!( "Duplicate plugin name detected ({}). Keeping the first instance.", plugin.name ); @@ -322,11 +322,11 @@ impl PluginManager { match result { Ok(_) => { plugin.state = PluginState::Enabled; - log::info!("Enabled PatchBukkit plugin: {}", plugin.name); + tracing::info!("Enabled PatchBukkit plugin: {}", plugin.name); } Err(e) => { plugin.state = PluginState::Errored; - log::error!( + tracing::error!( "Failed to enable PatchBukkit plugin {}: {:?}", plugin.name, e @@ -359,11 +359,11 @@ impl PluginManager { match result { Ok(_) => { plugin.state = PluginState::Disabled; - log::info!("Disabled PatchBukkit plugin: {}", plugin.name); + tracing::info!("Disabled PatchBukkit plugin: {}", plugin.name); } Err(e) => { plugin.state = PluginState::Disabled; - log::error!( + tracing::error!( "Failed to disable PatchBukkit plugin {}: {:?}", plugin.name, e @@ -422,7 +422,7 @@ impl PluginManager { { Ok(()) => (), Err(e) => { - log::error!( + tracing::error!( "Failed to register command {} for plugin {}: {:?}", cmd_name, plugin.name, @@ -433,7 +433,7 @@ impl PluginManager { } plugin.state = PluginState::Loaded; - log::info!("Loaded and registered commands for: {}", plugin.name); + tracing::info!("Loaded and registered commands for: {}", plugin.name); } Ok(()) } @@ -488,7 +488,7 @@ impl PluginManager { if let Some(plugin) = self.plugins.get_mut(&key) { plugin.state = PluginState::Errored; active.remove(&key); - log::warn!( + tracing::warn!( "Skipping plugin {} due to missing required dependencies: {}", plugin.name, missing_required.join(", ") @@ -569,7 +569,7 @@ impl PluginManager { let mut remaining: Vec = active.into_iter().filter(|k| !order.contains(k)).collect(); remaining.sort(); - log::warn!( + tracing::warn!( "Detected plugin dependency cycle(s). Loading remaining plugins in name order: {}", remaining.join(", ") ); diff --git a/rust/src/java/resources.rs b/rust/src/java/resources.rs index 56303cb..4023dd1 100644 --- a/rust/src/java/resources.rs +++ b/rust/src/java/resources.rs @@ -105,11 +105,11 @@ fn resolve_maven_dependencies(j4rs_folder: &Path) -> Result<()> { .all(|&(_, artifact, version)| jassets.join(format!("{artifact}-{version}.jar")).exists()); if all_present { - log::debug!("All Maven dependencies already present, skipping JVM init"); + tracing::debug!("All Maven dependencies already present, skipping JVM init"); return Ok(()); } - log::info!("Some Maven dependencies missing, starting JVM to resolve..."); + tracing::info!("Some Maven dependencies missing, starting JVM to resolve..."); let jvm = JvmBuilder::new() .with_maven_settings(MavenSettings::new(vec![MavenArtifactRepo::from( @@ -123,7 +123,7 @@ fn resolve_maven_dependencies(j4rs_folder: &Path) -> Result<()> { for &(group, artifact, version) in DEPENDENCIES { let jar_path = jassets.join(format!("{artifact}-{version}.jar")); if !jar_path.exists() { - log::info!("Downloading Maven dependency: {group}:{artifact}:{version}"); + tracing::info!("Downloading Maven dependency: {group}:{artifact}:{version}"); jvm.deploy_artifact(&MavenArtifact::from(format!( "{group}:{artifact}:{version}" ))) @@ -161,7 +161,7 @@ fn cleanup_stale_files(j4rs_folder: &Path) { } if !embedded_paths.contains(rel_path) { - log::warn!("Removing stale embedded file: {}", rel_path.display()); + tracing::warn!("Removing stale embedded file: {}", rel_path.display()); let _ = fs::remove_file(path); } } @@ -176,7 +176,7 @@ pub fn sync_embedded_resources(j4rs_folder: &Path) -> Result<()> { if resource_path.exists() { update_resource_if_changed(&resource_path, &resource.data)?; } else { - log::info!("Extracting new resource: {}", resource_path.display()); + tracing::info!("Extracting new resource: {}", resource_path.display()); write_resource(&resource_path, &resource.data)?; } } @@ -198,7 +198,7 @@ fn update_resource_if_changed(path: &Path, new_data: &[u8]) -> Result<()> { let size_matches = metadata.is_some_and(|m| m.len() == new_data.len() as u64); if !size_matches || fs::read(path)? != new_data { - log::debug!("Updating changed resource: {}", path.display()); + tracing::debug!("Updating changed resource: {}", path.display()); fs::write(path, new_data)?; } diff --git a/rust/src/lib.rs b/rust/src/lib.rs index 24c5f11..c8385e1 100644 --- a/rust/src/lib.rs +++ b/rust/src/lib.rs @@ -29,7 +29,7 @@ use crate::java::{ async fn on_load_inner(plugin: &PatchBukkitPlugin, server: Arc) -> Result<(), String> { server.init_log(); - log::info!("Starting PatchBukkit"); + tracing::info!("Starting PatchBukkit"); // Setup directories let dirs = setup_directories(&server)?; @@ -49,7 +49,7 @@ async fn on_load_inner(plugin: &PatchBukkitPlugin, server: Arc) -> Resu }) .await; if let Err(e) = result { - log::error!( + tracing::error!( "Failed to send command to load plugin {}: {}", jar_path.display(), e @@ -58,40 +58,40 @@ async fn on_load_inner(plugin: &PatchBukkitPlugin, server: Arc) -> Resu match rx.await { Ok(result) => match result { LoadPluginResult::SuccessfullyLoadedSpigot => { - log::info!("Loaded Spigot plugin from JAR `{}`", jar_path.display()); + tracing::info!("Loaded Spigot plugin from JAR `{}`", jar_path.display()); } LoadPluginResult::SuccessfullyLoadedPaper => { - log::info!("Loaded Paper plugin from JAR `{}`", jar_path.display()); + tracing::info!("Loaded Paper plugin from JAR `{}`", jar_path.display()); } LoadPluginResult::FailedToLoadSpigotPlugin(error) => { - log::error!( + tracing::error!( "Failed to load Spigot plugin from JAR `{}` with error: {}", jar_path.display(), error ); } LoadPluginResult::FailedToLoadPaperPlugin(error) => { - log::error!( + tracing::error!( "Failed to load Paper plugin from JAR `{}` with error: {}", jar_path.display(), error ); } LoadPluginResult::FailedToReadConfigurationFile(error) => { - log::error!( + tracing::error!( "Failed to read configuration file from JAR `{}`: {}", jar_path.display(), error ); } LoadPluginResult::NoConfigurationFile => { - log::warn!( + tracing::warn!( "No configuration file found for plugin from JAR `{}`", jar_path.display() ); } }, - Err(e) => log::error!( + Err(e) => tracing::error!( "Failed to receive load plugin response for JAR `{}`: {}", jar_path.display(), e diff --git a/rust/src/proto/mod.rs b/rust/src/proto/mod.rs index 64a6435..a958c5e 100644 --- a/rust/src/proto/mod.rs +++ b/rust/src/proto/mod.rs @@ -26,6 +26,10 @@ pub mod patchbukkit { pub mod sound { include!(concat!(env!("OUT_DIR"), "/patchbukkit.sound.rs")); } + + pub mod log { + include!(concat!(env!("OUT_DIR"), "/patchbukkit.log.rs")); + } } include!(concat!(env!("OUT_DIR"), "/ffi_init.rs"));