fix(node-swc): Correctly close trace spans after completion (#3811)

Cargo.lock

@@ -1374,9 +1374,9 @@ checksum = "7843ec2de400bcbc6a6328c958dc38e5359da6e93e72e37bc5246bf1ae776389"
 
 [[package]]
 name = "napi"
-version = "2.0.2"
+version = "2.1.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c4cfe7fef533df6323a5aa17d75cb162850f2b045adabb9922bfbd234426a1bb"
+checksum = "17ec66e60f000c78dd7c6215b6fa260e0591e09805024332bc5b3f55acc12244"
 dependencies = [
  "ctor",
  "lazy_static",
@@ -1394,9 +1394,9 @@ checksum = "ebd4419172727423cf30351406c54f6cc1b354a2cfb4f1dba3e6cd07f6d5522b"
 
 [[package]]
 name = "napi-derive"
-version = "2.0.7"
+version = "2.1.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c6978824526532976fe146f71fef50395840d64a6c1af9085a358bdfdd300c7d"
+checksum = "74ac5287a5e94a8728fc82d16c5127acc5eb5b8ad6404ef5f82d6a4ce8d5bdd2"
 dependencies = [
  "convert_case",
  "napi-derive-backend",
@@ -1407,9 +1407,9 @@ dependencies = [
 
 [[package]]
 name = "napi-derive-backend"
-version = "1.0.23"
+version = "1.0.25"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "30623da375dd5a5cae5609b0f0b9915177c03b3dc23a8450cc7dcc14027eee25"
+checksum = "427f4f04525635cdf22005d1be62d6d671bcb5550d694a1efb480a315422b4af"
 dependencies = [
  "convert_case",
  "once_cell",
@@ -3985,8 +3985,7 @@ dependencies = [
 [[package]]
 name = "tracing-chrome"
 version = "0.4.0"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "7fa213f0cfbe503fb51065f2663726b093dac7cda39401eac060d0ebd4b8415c"
+source = "git+https://github.com/kwonoj/tracing-chrome?rev=a345d8e#a345d8e8b0db52911711d01c9d44b1bdb7be2901"
 dependencies = [
  "json",
  "tracing",
@@ -4578,15 +4577,15 @@ checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f"
 
 [[package]]
 name = "windows"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "aac7fef12f4b59cd0a29339406cc9203ab44e440ddff6b3f5a41455349fa9cf3"
+checksum = "b749ebd2304aa012c5992d11a25d07b406bdbe5f79d371cb7a918ce501a19eb0"
 dependencies = [
- "windows_aarch64_msvc 0.29.0",
- "windows_i686_gnu 0.29.0",
- "windows_i686_msvc 0.29.0",
- "windows_x86_64_gnu 0.29.0",
- "windows_x86_64_msvc 0.29.0",
+ "windows_aarch64_msvc 0.30.0",
+ "windows_i686_gnu 0.30.0",
+ "windows_i686_msvc 0.30.0",
+ "windows_x86_64_gnu 0.30.0",
+ "windows_x86_64_msvc 0.30.0",
 ]
 
 [[package]]
@@ -4604,9 +4603,9 @@ dependencies = [
 
 [[package]]
 name = "windows_aarch64_msvc"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "c3d027175d00b01e0cbeb97d6ab6ebe03b12330a35786cbaca5252b1c4bf5d9b"
+checksum = "29277a4435d642f775f63c7d1faeb927adba532886ce0287bd985bffb16b6bca"
 
 [[package]]
 name = "windows_aarch64_msvc"
@@ -4616,9 +4615,9 @@ checksum = "d8e92753b1c443191654ec532f14c199742964a061be25d77d7a96f09db20bf5"
 
 [[package]]
 name = "windows_i686_gnu"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "8793f59f7b8e8b01eda1a652b2697d87b93097198ae85f823b969ca5b89bba58"
+checksum = "1145e1989da93956c68d1864f32fb97c8f561a8f89a5125f6a2b7ea75524e4b8"
 
 [[package]]
 name = "windows_i686_gnu"
@@ -4628,9 +4627,9 @@ checksum = "6a711c68811799e017b6038e0922cb27a5e2f43a2ddb609fe0b6f3eeda9de615"
 
 [[package]]
 name = "windows_i686_msvc"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "8602f6c418b67024be2996c512f5f995de3ba417f4c75af68401ab8756796ae4"
+checksum = "d4a09e3a0d4753b73019db171c1339cd4362c8c44baf1bcea336235e955954a6"
 
 [[package]]
 name = "windows_i686_msvc"
@@ -4640,9 +4639,9 @@ checksum = "146c11bb1a02615db74680b32a68e2d61f553cc24c4eb5b4ca10311740e44172"
 
 [[package]]
 name = "windows_x86_64_gnu"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "f3d615f419543e0bd7d2b3323af0d86ff19cbc4f816e6453f36a2c2ce889c354"
+checksum = "8ca64fcb0220d58db4c119e050e7af03c69e6f4f415ef69ec1773d9aab422d5a"
 
 [[package]]
 name = "windows_x86_64_gnu"
@@ -4652,9 +4651,9 @@ checksum = "c912b12f7454c6620635bbff3450962753834be2a594819bd5e945af18ec64bc"
 
 [[package]]
 name = "windows_x86_64_msvc"
-version = "0.29.0"
+version = "0.30.0"
 source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "11d95421d9ed3672c280884da53201a5c46b7b2765ca6faf34b0d71cf34a3561"
+checksum = "08cabc9f0066848fef4bc6a1c1668e6efce38b661d2aeec75d18d8617eebb5f1"
 
 [[package]]
 name = "windows_x86_64_msvc"

Cargo.toml

@@ -43,3 +43,5 @@ opt-level = 3
 [patch.crates-io]
 cranelift-codegen = { git = "https://github.com/kdy1/wasmtime", branch = "tls" }
 cranelift-entity = { git = "https://github.com/kdy1/wasmtime", branch = "tls" }
+# https://github.com/thoren-d/tracing-chrome/pull/6
+tracing-chrome = { git = "https://github.com/kwonoj/tracing-chrome", rev="a345d8e" }

crates/node/src/bundle.rs

@@ -186,7 +186,7 @@ pub(crate) fn bundle(
     conf_items: Buffer,
     signal: Option<AbortSignal>,
 ) -> napi::Result<AsyncTask<BundleTask>> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c: Arc<Compiler> = get_compiler();
 

crates/node/src/minify.rs

@@ -71,7 +71,7 @@ impl Task for MinifyTask {
 
 #[napi]
 fn minify(code: Buffer, opts: Buffer, signal: Option<AbortSignal>) -> AsyncTask<MinifyTask> {
-    crate::util::init_trace_once(false, None).expect("Should able to init trace");
+    crate::util::init_default_trace_subscriber();
     let code = String::from_utf8_lossy(code.as_ref()).to_string();
     let options = String::from_utf8_lossy(opts.as_ref()).to_string();
 
@@ -84,7 +84,7 @@ fn minify(code: Buffer, opts: Buffer, signal: Option<AbortSignal>) -> AsyncTask<
 
 #[napi]
 pub fn minify_sync(code: Buffer, opts: Buffer) -> napi::Result<TransformOutput> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
     let code: MinifyTarget = get_deserialized(code)?;
     let opts = get_deserialized(opts)?;
 

crates/node/src/parse.rs

@@ -110,7 +110,7 @@ pub fn parse(
     filename: Option<String>,
     signal: Option<AbortSignal>,
 ) -> AsyncTask<ParseTask> {
-    crate::util::init_trace_once(false, None).expect("Should able to init trace");
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
     let options = String::from_utf8_lossy(options.as_ref()).to_string();
@@ -133,7 +133,7 @@ pub fn parse(
 
 #[napi]
 pub fn parse_sync(src: String, opts: Buffer, filename: Option<String>) -> napi::Result<String> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
     let c = get_compiler();
 
     let options: ParseOptions = get_deserialized(&opts)?;
@@ -163,7 +163,7 @@ pub fn parse_sync(src: String, opts: Buffer, filename: Option<String>) -> napi::
 
 #[napi]
 pub fn parse_file_sync(path: String, opts: Buffer) -> napi::Result<String> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
     let c = get_compiler();
     let options: ParseOptions = get_deserialized(&opts)?;
 
@@ -194,7 +194,7 @@ pub fn parse_file(
     options: Buffer,
     signal: Option<AbortSignal>,
 ) -> AsyncTask<ParseFileTask> {
-    crate::util::init_trace_once(false, None).expect("Should able to init trace");
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
     let path = PathBuf::from(&path);

crates/node/src/print.rs

@@ -62,7 +62,7 @@ pub fn print(
     options: Buffer,
     signal: Option<AbortSignal>,
 ) -> napi::Result<AsyncTask<PrintTask>> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
     let options = String::from_utf8_lossy(&options).to_string();
@@ -79,7 +79,7 @@ pub fn print(
 
 #[napi]
 pub fn print_sync(program: String, options: Buffer) -> napi::Result<TransformOutput> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
 

crates/node/src/transform.rs

@@ -101,7 +101,7 @@ pub fn transform(
     options: JsBuffer,
     signal: Option<AbortSignal>,
 ) -> napi::Result<AsyncTask<TransformTask>> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
 
@@ -122,7 +122,7 @@ pub fn transform(
 #[napi]
 #[instrument(level = "trace", skip_all)]
 pub fn transform_sync(s: String, is_module: bool, opts: Buffer) -> napi::Result<TransformOutput> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
 
@@ -162,7 +162,7 @@ pub fn transform_file(
     options: JsBuffer,
     signal: Option<AbortSignal>,
 ) -> napi::Result<AsyncTask<TransformTask>> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
 
@@ -181,7 +181,7 @@ pub fn transform_file_sync(
     is_module: bool,
     opts: Buffer,
 ) -> napi::Result<TransformOutput> {
-    crate::util::init_trace_once(false, None)?;
+    crate::util::init_default_trace_subscriber();
 
     let c = get_compiler();
 

crates/node/src/util.rs

@@ -1,69 +1,55 @@
 use std::{
     any::type_name,
     panic::{catch_unwind, AssertUnwindSafe},
-    sync::Mutex,
 };
 
 use anyhow::{anyhow, Context, Error};
-use napi::Status;
+use napi::{Env, Status};
 use serde::de::DeserializeOwned;
 use swc::try_with_handler;
-use swc_common::{
-    errors::Handler,
-    sync::{Lrc, OnceCell},
-    SourceMap,
-};
+use swc_common::{errors::Handler, sync::Lrc, SourceMap};
 use tracing::instrument;
-use tracing_chrome::{ChromeLayerBuilder, FlushGuard};
+use tracing_chrome::ChromeLayerBuilder;
 use tracing_subscriber::{
     prelude::__tracing_subscriber_SubscriberExt, util::SubscriberInitExt, EnvFilter,
 };
 
-// Hold FlushGuard for the trace until it flushes out completely.
-#[derive(Default)]
-struct TraceFlushGuard {
-    inner: Option<FlushGuard>,
-}
-static FLUSH_GUARD: OnceCell<Mutex<TraceFlushGuard>> = OnceCell::new();
-
 #[napi]
-pub fn init_trace_once(
-    enable_chrome_trace: bool,
-    trace_out_file: Option<String>,
+pub fn init_custom_trace_subscriber(
+    mut env: Env,
+    trace_out_file_path: Option<String>,
 ) -> napi::Result<()> {
-    FLUSH_GUARD.get_or_init(|| {
-        if enable_chrome_trace {
-            let layer = if let Some(trace_out_file) = trace_out_file {
-                ChromeLayerBuilder::new()
-                    .file(trace_out_file)
-                    .include_args(true)
-            } else {
-                ChromeLayerBuilder::new().include_args(true)
-            };
+    let mut layer = ChromeLayerBuilder::new().include_args(true);
+    if let Some(trace_out_file) = trace_out_file_path {
+        layer = layer.file(trace_out_file);
+    }
 
-            let (chrome_layer, guard) = layer.build();
-            tracing_subscriber::registry()
-                .with(chrome_layer)
-                .try_init()
-                .expect("Should able to register trace");
+    let (chrome_layer, guard) = layer.build();
+    tracing_subscriber::registry()
+        .with(chrome_layer)
+        .try_init()
+        .expect("Failed to register tracing subscriber");
 
-            Mutex::new(TraceFlushGuard { inner: Some(guard) })
-        } else {
-            tracing_subscriber::FmtSubscriber::builder()
-                .without_time()
-                .with_target(false)
-                .with_ansi(true)
-                .with_env_filter(EnvFilter::from_env("SWC_LOG"))
-                .try_init()
-                .expect("Should able to register trace");
-
-            Mutex::new(TraceFlushGuard { inner: None })
-        }
-    });
+    env.add_env_cleanup_hook(guard, |flush_guard| {
+        flush_guard.flush();
+        drop(flush_guard);
+    })?;
 
     Ok(())
 }
 
+/// Trying to initialize default subscriber if global dispatch is not set.
+/// This can be called multiple time, however subsequent calls will be ignored
+/// as tracing_subscriber only allows single global dispatch.
+pub fn init_default_trace_subscriber() {
+    let _unused = tracing_subscriber::FmtSubscriber::builder()
+        .without_time()
+        .with_target(false)
+        .with_ansi(true)
+        .with_env_filter(EnvFilter::from_env("SWC_LOG"))
+        .try_init();
+}
+
 #[instrument(level = "trace", skip_all)]
 pub fn try_with<F, Ret>(cm: Lrc<SourceMap>, skip_filename: bool, op: F) -> Result<Ret, Error>
 where

crates/swc_plugin_runner/src/cache.rs

@@ -48,6 +48,7 @@ pub struct PluginModuleCache {
     instantiation_lock: Mutex<()>,
 }
 
+#[tracing::instrument(level = "trace", skip_all)]
 fn create_filesystem_cache(filesystem_cache_root: &Option<String>) -> Option<FileSystemCache> {
     let mut root_path = if let Some(root) = filesystem_cache_root {
         Some(PathBuf::from(root))
@@ -105,6 +106,7 @@ impl PluginModuleCache {
     /// [This code](https://github.com/swc-project/swc/blob/fc4c6708f24cda39640fbbfe56123f2f6eeb2474/crates/swc/src/plugin.rs#L19-L44)
     /// includes previous incorrect attempt to workaround file read issues.
     /// In actual transform, `plugins` is also being called per each transform.
+    #[tracing::instrument(level = "trace", skip_all)]
     pub fn load_module(&self, binary_path: &Path) -> Result<Module, Error> {
         let binary_path = binary_path.to_path_buf();
         let mut inner_cache = self.inner.get().expect("Cache should be available").lock();
@@ -124,8 +126,17 @@ impl PluginModuleCache {
         let wasmer_store = Store::default();
 
         let load_cold_wasm_bytes = || {
+            let span = tracing::span!(
+                tracing::Level::TRACE,
+                "load_cold_wasm_bytes",
+                plugin_module = binary_path.to_str()
+            );
+            let span_guard = span.enter();
             let _lock = self.instantiation_lock.lock();
-            Module::new(&wasmer_store, module_bytes).context("Cannot compile plugin binary")
+            let ret =
+                Module::new(&wasmer_store, module_bytes).context("Cannot compile plugin binary");
+            drop(span_guard);
+            ret
         };
 
         // Try to load compiled bytes from filesystem cache if available.

node-swc/src/binding.d.ts

@@ -26,7 +26,7 @@ export function transform(src: string, isModule: boolean, options: Buffer, signa
 export function transformSync(s: string, isModule: boolean, opts: Buffer): TransformOutput
 export function transformFile(src: string, isModule: boolean, options: Buffer, signal?: AbortSignal | undefined | null): Promise<TransformOutput>
 export function transformFileSync(s: string, isModule: boolean, opts: Buffer): TransformOutput
-export function initTraceOnce(enableChromeTrace: boolean, traceOutFile?: string | undefined | null): void
+export function initCustomTraceSubscriber(traceOutFilePath?: string | undefined | null): void
 /** Hack for `Type Generation` */
 export interface TransformOutput {
   code: string

node-swc/src/binding.js

@@ -236,7 +236,7 @@ if (!nativeBinding) {
   throw new Error(`Failed to load native binding`)
 }
 
-const { bundle, minify, minifySync, parse, parseSync, parseFileSync, parseFile, print, printSync, transform, transformSync, transformFile, transformFileSync, initTraceOnce, Compiler } = nativeBinding
+const { bundle, minify, minifySync, parse, parseSync, parseFileSync, parseFile, print, printSync, transform, transformSync, transformFile, transformFileSync, initCustomTraceSubscriber, Compiler } = nativeBinding
 
 module.exports.bundle = bundle
 module.exports.minify = minify
@@ -251,5 +251,5 @@ module.exports.transform = transform
 module.exports.transformSync = transformSync
 module.exports.transformFile = transformFile
 module.exports.transformFileSync = transformFileSync
-module.exports.initTraceOnce = initTraceOnce
+module.exports.initCustomTraceSubscriber = initCustomTraceSubscriber
 module.exports.Compiler = Compiler

node-swc/src/index.ts

@@ -329,7 +329,9 @@ export function __experimental_registerGlobalTraceConfig(traceConfig: {
   type: 'traceEvent',
   fileName?: string
 }) {
-  bindings.initTraceOnce(traceConfig.type === 'traceEvent', traceConfig.fileName);
+  if (traceConfig.type === 'traceEvent') {
+    bindings.initCustomTraceSubscriber(traceConfig.fileName);
+  }
 }
 
 export const DEFAULT_EXTENSIONS = Object.freeze([

tests/rust-plugins/swc_internal_plugin/Cargo.lock

@@ -778,7 +778,7 @@ dependencies = [
 
 [[package]]
 name = "swc_ecma_parser"
-version = "0.91.12"
+version = "0.91.13"
 dependencies = [
  "either",
  "enum_kind",