From 837e0a6af8afc4b90866ec94672e4f04afaf81b4 Mon Sep 17 00:00:00 2001 From: OJ Kwon Date: Mon, 2 May 2022 15:20:59 -0700 Subject: [PATCH] feat(next-swc): introduce experimental tracing support for swc (#35803) * feat(next-swc/napi): expose initcustomtracesubscriber * feat(next/config): enable experimental swcTrace * feat(trace): add trace for emotion transform * refactor(swc): use .next for the default trace output * refactor(swc): teardown subscriber via drop * refactor(swc/trace): simplify config * refactor(swc/trace): adjust teardown --- packages/next-swc/Cargo.lock | 53 +++++++++++++++++ packages/next-swc/crates/core/Cargo.toml | 3 +- packages/next-swc/crates/emotion/Cargo.toml | 2 + packages/next-swc/crates/emotion/src/lib.rs | 2 + packages/next-swc/crates/napi/Cargo.toml | 5 ++ packages/next-swc/crates/napi/src/lib.rs | 5 ++ packages/next-swc/crates/napi/src/util.rs | 63 +++++++++++++++++++-- packages/next/build/index.ts | 3 +- packages/next/build/output/store.ts | 5 +- packages/next/build/swc/index.d.ts | 2 + packages/next/build/swc/index.js | 43 ++++++++++++++ packages/next/build/webpack-config.ts | 10 ++++ packages/next/server/config-shared.ts | 1 + 13 files changed, 189 insertions(+), 8 deletions(-) diff --git a/packages/next-swc/Cargo.lock b/packages/next-swc/Cargo.lock index 2de4a78596dc..87e15cb8c10f 100644 --- a/packages/next-swc/Cargo.lock +++ b/packages/next-swc/Cargo.lock @@ -717,6 +717,12 @@ dependencies = [ "wasm-bindgen", ] +[[package]] +name = "json" +version = "0.12.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "078e285eafdfb6c4b434e0d31e8cfcb5115b651496faca5749b88fafd4f23bfd" + [[package]] name = "json_comments" version = "0.2.1" @@ -1043,6 +1049,10 @@ dependencies = [ "swc_ecma_loader", "swc_ecmascript", "swc_node_base", + "tracing", + "tracing-chrome", + "tracing-futures", + "tracing-subscriber", ] [[package]] @@ -1303,6 +1313,26 @@ dependencies = [ "siphasher", ] +[[package]] +name = "pin-project" +version = "1.0.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "58ad3879ad3baf4e44784bc6a718a8698867bb991f8ce24d1bcbe2cfb4c3a75e" +dependencies = [ + "pin-project-internal", +] + +[[package]] +name = "pin-project-internal" +version = "1.0.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "744b6f092ba29c3650faf274db506afd39944f48420f6c86b17cfe0ee1cb36bb" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + [[package]] name = "pin-project-lite" version = "0.2.8" @@ -2555,7 +2585,9 @@ dependencies = [ "swc_common", "swc_ecma_transforms_testing", "swc_ecmascript", + "swc_trace_macro", "testing", + "tracing", ] [[package]] @@ -2851,6 +2883,17 @@ dependencies = [ "syn", ] +[[package]] +name = "tracing-chrome" +version = "0.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "fcb13184244c7cd22758b79e7c993c515ad67a8e730edcb7e05fe7bcabb283c7" +dependencies = [ + "json", + "tracing", + "tracing-subscriber", +] + [[package]] name = "tracing-core" version = "0.1.26" @@ -2861,6 +2904,16 @@ dependencies = [ "valuable", ] +[[package]] +name = "tracing-futures" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "97d095ae15e245a057c8e8451bab9b3ee1e1f68e9ba2b4fbc18d0ac5237835f2" +dependencies = [ + "pin-project", + "tracing", +] + [[package]] name = "tracing-log" version = "0.1.2" diff --git a/packages/next-swc/crates/core/Cargo.toml b/packages/next-swc/crates/core/Cargo.toml index f2328655479c..b1bf2d334fcd 100644 --- a/packages/next-swc/crates/core/Cargo.toml +++ b/packages/next-swc/crates/core/Cargo.toml @@ -27,8 +27,7 @@ swc_common = { version = "0.17.25", features = ["concurrent", "sourcemap"] } swc_ecma_loader = { version = "0.29.1", features = ["node", "lru"] } swc_ecmascript = { version = "0.150.0", features = ["codegen", "minifier", "optimization", "parser", "react", "transforms", "typescript", "utils", "visit"] } swc_cached = "0.1.1" -tracing = { version = "0.1.32", features = ["release_max_level_off"] } - +tracing = { version = "0.1.32", features = ["release_max_level_info"] } [dev-dependencies] swc_ecma_transforms_testing = "0.82.0" diff --git a/packages/next-swc/crates/emotion/Cargo.toml b/packages/next-swc/crates/emotion/Cargo.toml index 545b5b0689a5..175fdcda5704 100644 --- a/packages/next-swc/crates/emotion/Cargo.toml +++ b/packages/next-swc/crates/emotion/Cargo.toml @@ -21,6 +21,8 @@ sourcemap = "6.0.1" swc_atoms = "0.2.11" swc_common = { version = "0.17.25", features = ["concurrent", "sourcemap"] } swc_ecmascript = { version = "0.150.0", features = ["codegen", "utils", "visit"] } +swc_trace_macro = "0.1.1" +tracing = { version = "0.1.32", features = ["release_max_level_info"] } [dev-dependencies] swc_ecma_transforms_testing = "0.82.0" diff --git a/packages/next-swc/crates/emotion/src/lib.rs b/packages/next-swc/crates/emotion/src/lib.rs index ff89be748a3e..795070aa3a51 100644 --- a/packages/next-swc/crates/emotion/src/lib.rs +++ b/packages/next-swc/crates/emotion/src/lib.rs @@ -25,6 +25,7 @@ use swc_ecmascript::{ codegen::util::SourceMapperExt, visit::{Fold, FoldWith}, }; +use swc_trace_macro::swc_trace; mod hash; @@ -164,6 +165,7 @@ pub struct EmotionTransformer { in_jsx_element: bool, } +#[swc_trace] impl EmotionTransformer { pub fn new(options: EmotionOptions, path: &Path, cm: Arc, comments: C) -> Self { EmotionTransformer { diff --git a/packages/next-swc/crates/napi/Cargo.toml b/packages/next-swc/crates/napi/Cargo.toml index 36113153c3dd..30a8df56de35 100644 --- a/packages/next-swc/crates/napi/Cargo.toml +++ b/packages/next-swc/crates/napi/Cargo.toml @@ -24,6 +24,11 @@ swc_common = { version = "0.17.25", features = ["concurrent", "sourcemap"] } swc_ecma_loader = { version = "0.29.1", features = ["node", "lru"] } swc_ecmascript = { version = "0.150.0", features = ["codegen", "minifier", "optimization", "parser", "react", "transforms", "typescript", "utils", "visit"] } swc_node_base = "0.5.2" +tracing = { version = "0.1.32", features = ["release_max_level_info"] } +tracing-futures = "0.2.5" +tracing-subscriber = "0.3.9" + +tracing-chrome = "0.5.0" [build-dependencies] napi-build = "1" diff --git a/packages/next-swc/crates/napi/src/lib.rs b/packages/next-swc/crates/napi/src/lib.rs index 477108aabefb..12f1c1e4c0cd 100644 --- a/packages/next-swc/crates/napi/src/lib.rs +++ b/packages/next-swc/crates/napi/src/lib.rs @@ -73,6 +73,11 @@ fn init(mut exports: JsObject) -> napi::Result<()> { exports.create_named_method("parse", parse::parse)?; exports.create_named_method("getTargetTriple", util::get_target_triple)?; + exports.create_named_method( + "initCustomTraceSubscriber", + util::init_custom_trace_subscriber, + )?; + exports.create_named_method("teardownTraceSubscriber", util::teardown_trace_subscriber)?; Ok(()) } diff --git a/packages/next-swc/crates/napi/src/util.rs b/packages/next-swc/crates/napi/src/util.rs index 868079445413..8476ff55d6e6 100644 --- a/packages/next-swc/crates/napi/src/util.rs +++ b/packages/next-swc/crates/napi/src/util.rs @@ -26,13 +26,14 @@ IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. */ -use anyhow::{Context, Error}; -use napi::{CallContext, Env, JsBuffer, JsString, Status}; +use anyhow::{anyhow, Context, Error}; +use napi::{CallContext, Env, JsBuffer, JsExternal, JsString, JsUndefined, JsUnknown, Status}; use serde::de::DeserializeOwned; -use std::any::type_name; +use std::{any::type_name, cell::RefCell, convert::TryFrom, path::PathBuf}; +use tracing_chrome::{ChromeLayerBuilder, FlushGuard}; +use tracing_subscriber::{filter, prelude::*, util::SubscriberInitExt, Layer}; static TARGET_TRIPLE: &str = include_str!(concat!(env!("OUT_DIR"), "/triple.txt")); - #[contextless_function] pub fn get_target_triple(env: Env) -> napi::ContextlessResult { env.create_string(TARGET_TRIPLE).map(Some) @@ -89,3 +90,57 @@ where serde_json::from_str(s) .with_context(|| format!("failed to deserialize as {}\nJSON: {}", type_name::(), s)) } + +/// Initialize tracing subscriber to emit traces. This configures subscribers +/// for Trace Event Format (https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview). +#[js_function(1)] +pub fn init_custom_trace_subscriber(cx: CallContext) -> napi::Result { + let optional_trace_out_file_path = cx.get::(0)?; + let trace_out_file_path = match optional_trace_out_file_path.get_type()? { + napi::ValueType::String => Some(PathBuf::from( + JsString::try_from(optional_trace_out_file_path)? + .into_utf8()? + .as_str()? + .to_owned(), + )), + _ => None, + }; + + let mut layer = ChromeLayerBuilder::new().include_args(true); + if let Some(trace_out_file) = trace_out_file_path { + let dir = trace_out_file + .parent() + .ok_or_else(|| anyhow!("Not able to find path to the trace output")) + .convert_err()?; + std::fs::create_dir_all(dir)?; + + layer = layer.file(trace_out_file); + } + + let (chrome_layer, guard) = layer.build(); + tracing_subscriber::registry() + .with(chrome_layer.with_filter(filter::filter_fn(|metadata| { + !metadata.target().contains("cranelift") && !metadata.name().contains("log ") + }))) + .try_init() + .expect("Failed to register tracing subscriber"); + + let guard_cell = RefCell::new(Some(guard)); + cx.env.create_external(guard_cell, None) +} + +/// Teardown currently running tracing subscriber to flush out remaining traces. +/// This should be called when parent node.js process exits, otherwise generated +/// trace may drop traces in the buffer. +#[js_function(1)] +pub fn teardown_trace_subscriber(cx: CallContext) -> napi::Result { + let guard_external = cx.get::(0)?; + let guard_cell = &*cx + .env + .get_value_external::>>(&guard_external)?; + + if let Some(guard) = guard_cell.take() { + drop(guard); + } + cx.env.get_undefined() +} diff --git a/packages/next/build/index.ts b/packages/next/build/index.ts index 1e2bd262d40c..4390a97824b7 100644 --- a/packages/next/build/index.ts +++ b/packages/next/build/index.ts @@ -113,7 +113,7 @@ import { TelemetryPlugin } from './webpack/plugins/telemetry-plugin' import { MiddlewareManifest } from './webpack/plugins/middleware-plugin' import { recursiveCopy } from '../lib/recursive-copy' import { recursiveReadDir } from '../lib/recursive-readdir' -import { lockfilePatchPromise } from './swc' +import { lockfilePatchPromise, teardownTraceSubscriber } from './swc' export type SsgRoute = { initialRevalidateSeconds: number | false @@ -2212,6 +2212,7 @@ export default async function build( // Ensure all traces are flushed before finishing the command await flushAllTraces() + teardownTraceSubscriber() } } diff --git a/packages/next/build/output/store.ts b/packages/next/build/output/store.ts index d2520f71f015..4397f6271de0 100644 --- a/packages/next/build/output/store.ts +++ b/packages/next/build/output/store.ts @@ -1,7 +1,7 @@ import createStore from 'next/dist/compiled/unistore' import stripAnsi from 'next/dist/compiled/strip-ansi' import { flushAllTraces } from '../../trace' - +import { teardownTraceSubscriber } from '../swc' import * as Log from './log' export type OutputState = @@ -91,6 +91,7 @@ store.subscribe((state) => { // Ensure traces are flushed after each compile in development mode flushAllTraces() + teardownTraceSubscriber() return } @@ -117,6 +118,7 @@ store.subscribe((state) => { Log.warn(state.warnings.join('\n\n')) // Ensure traces are flushed after each compile in development mode flushAllTraces() + teardownTraceSubscriber() return } @@ -132,4 +134,5 @@ store.subscribe((state) => { ) // Ensure traces are flushed after each compile in development mode flushAllTraces() + teardownTraceSubscriber() }) diff --git a/packages/next/build/swc/index.d.ts b/packages/next/build/swc/index.d.ts index 162a1b55e847..564090d59b22 100644 --- a/packages/next/build/swc/index.d.ts +++ b/packages/next/build/swc/index.d.ts @@ -6,3 +6,5 @@ export function minifySync(src: string, options: any): string export function bundle(options: any): Promise export function parse(src: string, options: any): any export const lockfilePatchPromise: { cur?: Promise } +export function initCustomTraceSubscriber(traceFileName?: string): void +export function teardownTraceSubscriber(): void diff --git a/packages/next/build/swc/index.js b/packages/next/build/swc/index.js index 59bf712787db..b3488bf9495b 100644 --- a/packages/next/build/swc/index.js +++ b/packages/next/build/swc/index.js @@ -17,6 +17,7 @@ let nativeBindings let wasmBindings let downloadWasmPromise let pendingBindings +let swcTraceFlushGuard export const lockfilePatchPromise = {} async function loadBindings() { @@ -261,6 +262,8 @@ function loadNative() { }, getTargetTriple: bindings.getTargetTriple, + initCustomTraceSubscriber: bindings.initCustomTraceSubscriber, + teardownTraceSubscriber: bindings.teardownTraceSubscriber, } return nativeBindings } @@ -320,3 +323,43 @@ export function getBinaryMetadata() { target: bindings?.getTargetTriple?.(), } } + +/** + * Initialize trace subscriber to emit traces. + * + */ +export const initCustomTraceSubscriber = (() => { + return (filename) => { + if (!swcTraceFlushGuard) { + // Wasm binary doesn't support trace emission + let bindings = loadNative() + swcTraceFlushGuard = bindings.initCustomTraceSubscriber(filename) + } + } +})() + +/** + * Teardown swc's trace subscriber if there's an initialized flush guard exists. + * + * This is workaround to amend behavior with process.exit + * (https://github.com/vercel/next.js/blob/4db8c49cc31e4fc182391fae6903fb5ef4e8c66e/packages/next/bin/next.ts#L134=) + * seems preventing napi's cleanup hook execution (https://github.com/swc-project/swc/blob/main/crates/node/src/util.rs#L48-L51=), + * + * instead parent process manually drops guard when process gets signal to exit. + */ +export const teardownTraceSubscriber = (() => { + let flushed = false + return () => { + if (!flushed) { + flushed = true + try { + let bindings = loadNative() + if (swcTraceFlushGuard) { + bindings.teardownTraceSubscriber(swcTraceFlushGuard) + } + } catch (e) { + // Suppress exceptions, this fn allows to fail to load native bindings + } + } + } +})() diff --git a/packages/next/build/webpack-config.ts b/packages/next/build/webpack-config.ts index fab5cbf8f8a9..9a96c22689b5 100644 --- a/packages/next/build/webpack-config.ts +++ b/packages/next/build/webpack-config.ts @@ -436,6 +436,16 @@ export default async function getBaseWebpackConfig( } const getBabelOrSwcLoader = () => { + if (useSWCLoader && config?.experimental?.swcTraceProfiling) { + // This will init subscribers once only in a single process lifecycle, + // even though it can be called multiple times. + // Subscriber need to be initialized _before_ any actual swc's call (transform, etcs) + // to collect correct trace spans when they are called. + require('./swc')?.initCustomTraceSubscriber?.( + path.join(distDir, `swc-trace-profile-${Date.now()}.json`) + ) + } + return useSWCLoader ? { loader: 'next-swc-loader', diff --git a/packages/next/server/config-shared.ts b/packages/next/server/config-shared.ts index c90d19cebba8..ebde47189cc0 100644 --- a/packages/next/server/config-shared.ts +++ b/packages/next/server/config-shared.ts @@ -132,6 +132,7 @@ export interface ExperimentalConfig { skipDefaultConversion?: boolean } > + swcTraceProfiling?: boolean } /**