From f7a62356092f0c0d4f137b1091b5c505e83bc8ec Mon Sep 17 00:00:00 2001 From: legendecas Date: Thu, 28 Jul 2022 08:09:30 +0800 Subject: [PATCH] src,lib: print source map error source on demand The source context is not prepended to the value of the `stack` property when the source map is not enabled. Rather than prepending the error source context to the value of the `stack` property unconditionally, this patch aligns the behavior and only prints the source context when the error is not handled by userland (e.g. fatal errors). Also, this patch fixes that when source-map support is enabled, the error source context is not pointing to where the error was thrown. PR-URL: https://github.com/nodejs/node/pull/43875 Fixes: https://github.com/nodejs/node/issues/43186 Fixes: https://github.com/nodejs/node/issues/41541 Reviewed-By: Ben Coe Reviewed-By: Matteo Collina --- .eslintignore | 1 + benchmark/es/error-stack.js | 34 +++++++ benchmark/fixtures/simple-error-stack.js | 15 +++ benchmark/fixtures/simple-error-stack.ts | 17 ++++ .../source_map/prepare_stack_trace.js | 44 +++++---- lib/internal/source_map/source_map_cache.js | 91 +++++++++++-------- src/env.h | 1 + src/node_errors.cc | 56 +++++++++++- test/message/source_map_disabled_by_api.js | 6 +- test/message/source_map_disabled_by_api.out | 6 -- test/message/source_map_enabled_by_api.js | 6 +- test/message/source_map_enabled_by_api.out | 10 -- .../message/source_map_enclosing_function.out | 6 +- test/message/source_map_eval.out | 4 + test/message/source_map_throw_catch.out | 3 - test/message/source_map_throw_first_tick.out | 2 +- test/message/source_map_throw_icu.out | 2 +- .../source_map_throw_set_immediate.out | 2 +- 18 files changed, 219 insertions(+), 87 deletions(-) create mode 100644 benchmark/es/error-stack.js create mode 100644 benchmark/fixtures/simple-error-stack.js create mode 100644 benchmark/fixtures/simple-error-stack.ts diff --git a/.eslintignore b/.eslintignore index 5941496e1a6280..153ac6e24f731e 100644 --- a/.eslintignore +++ b/.eslintignore @@ -6,6 +6,7 @@ test/message/esm_display_syntax_error.mjs tools/icu tools/lint-md/lint-md.mjs benchmark/tmp +benchmark/fixtures doc/**/*.js !doc/api_assets/*.js !.eslintrc.js diff --git a/benchmark/es/error-stack.js b/benchmark/es/error-stack.js new file mode 100644 index 00000000000000..907f308ea41558 --- /dev/null +++ b/benchmark/es/error-stack.js @@ -0,0 +1,34 @@ +'use strict'; + +const common = require('../common.js'); +const modPath = require.resolve('../fixtures/simple-error-stack.js'); + +const bench = common.createBenchmark(main, { + method: ['without-sourcemap', 'sourcemap'], + n: [1e5], +}); + +function runN(n) { + delete require.cache[modPath]; + const mod = require(modPath); + bench.start(); + for (let i = 0; i < n; i++) { + mod.simpleErrorStack(); + } + bench.end(n); +} + +function main({ n, method }) { + switch (method) { + case 'without-sourcemap': + process.setSourceMapsEnabled(false); + runN(n); + break; + case 'sourcemap': + process.setSourceMapsEnabled(true); + runN(n); + break; + default: + throw new Error(`Unexpected method "${method}"`); + } +} diff --git a/benchmark/fixtures/simple-error-stack.js b/benchmark/fixtures/simple-error-stack.js new file mode 100644 index 00000000000000..0057807795b072 --- /dev/null +++ b/benchmark/fixtures/simple-error-stack.js @@ -0,0 +1,15 @@ +'use strict'; +exports.__esModule = true; +exports.simpleErrorStack = void 0; +// Compile with `tsc --inlineSourceMap benchmark/fixtures/simple-error-stack.ts`. +var lorem = 'Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident, sunt in culpa qui officia deserunt mollit anim id est laborum.'; +function simpleErrorStack() { + try { + lorem.BANG(); + } + catch (e) { + return e.stack; + } +} +exports.simpleErrorStack = simpleErrorStack; +//# sourceMappingURL=data:application/json;base64,eyJ2ZXJzaW9uIjozLCJmaWxlIjoic2ltcGxlLWVycm9yLXN0YWNrLmpzIiwic291cmNlUm9vdCI6IiIsInNvdXJjZXMiOlsic2ltcGxlLWVycm9yLXN0YWNrLnRzIl0sIm5hbWVzIjpbXSwibWFwcGluZ3MiOiJBQUFBLFlBQVksQ0FBQzs7O0FBRWIsaUZBQWlGO0FBRWpGLElBQU0sS0FBSyxHQUFHLCtiQUErYixDQUFDO0FBRTljLFNBQVMsZ0JBQWdCO0lBQ3ZCLElBQUk7UUFDRCxLQUFhLENBQUMsSUFBSSxFQUFFLENBQUM7S0FDdkI7SUFBQyxPQUFPLENBQUMsRUFBRTtRQUNWLE9BQU8sQ0FBQyxDQUFDLEtBQUssQ0FBQztLQUNoQjtBQUNILENBQUM7QUFHQyw0Q0FBZ0IifQ== diff --git a/benchmark/fixtures/simple-error-stack.ts b/benchmark/fixtures/simple-error-stack.ts new file mode 100644 index 00000000000000..58034e92f24b98 --- /dev/null +++ b/benchmark/fixtures/simple-error-stack.ts @@ -0,0 +1,17 @@ +'use strict'; + +// Compile with `tsc --inlineSourceMap benchmark/fixtures/simple-error-stack.ts`. + +const lorem = 'Lorem ipsum dolor sit amet, consectetur adipiscing elit, sed do eiusmod tempor incididunt ut labore et dolore magna aliqua. Ut enim ad minim veniam, quis nostrud exercitation ullamco laboris nisi ut aliquip ex ea commodo consequat. Duis aute irure dolor in reprehenderit in voluptate velit esse cillum dolore eu fugiat nulla pariatur. Excepteur sint occaecat cupidatat non proident, sunt in culpa qui officia deserunt mollit anim id est laborum.'; + +function simpleErrorStack() { + try { + (lorem as any).BANG(); + } catch (e) { + return e.stack; + } +} + +export { + simpleErrorStack, +}; diff --git a/lib/internal/source_map/prepare_stack_trace.js b/lib/internal/source_map/prepare_stack_trace.js index 55dc8b344f8be6..d01ca2bedd52b8 100644 --- a/lib/internal/source_map/prepare_stack_trace.js +++ b/lib/internal/source_map/prepare_stack_trace.js @@ -25,6 +25,7 @@ const { kIsNodeError, } = require('internal/errors'); const { fileURLToPath } = require('internal/url'); +const { setGetSourceMapErrorSource } = internalBinding('errors'); // Create a prettified stacktrace, inserting context from source maps // if possible. @@ -53,7 +54,6 @@ const prepareStackTrace = (globalThis, error, trace) => { return errorString; } - let errorSource = ''; let lastSourceMap; let lastFileName; const preparedTrace = ArrayPrototypeJoin(ArrayPrototypeMap(trace, (t, i) => { @@ -62,14 +62,12 @@ const prepareStackTrace = (globalThis, error, trace) => { // A stack trace will often have several call sites in a row within the // same file, cache the source map and file content accordingly: let fileName = t.getFileName(); - let generated = false; if (fileName === undefined) { fileName = t.getEvalOrigin(); - generated = true; } const sm = fileName === lastFileName ? lastSourceMap : - findSourceMap(fileName, generated); + findSourceMap(fileName); lastSourceMap = sm; lastFileName = fileName; if (sm) { @@ -83,14 +81,6 @@ const prepareStackTrace = (globalThis, error, trace) => { if (originalSource && originalLine !== undefined && originalColumn !== undefined) { const name = getOriginalSymbolName(sm, trace, i); - if (i === 0) { - errorSource = getErrorSource( - sm, - originalSource, - originalLine, - originalColumn - ); - } // Construct call site name based on: v8.dev/docs/stack-trace-api: const fnName = t.getFunctionName() ?? t.getMethodName(); const typeName = t.getTypeName(); @@ -116,7 +106,7 @@ const prepareStackTrace = (globalThis, error, trace) => { } return `${str}${t}`; }), ''); - return `${errorSource}${errorString}\n at ${preparedTrace}`; + return `${errorString}\n at ${preparedTrace}`; }; // Transpilers may have removed the original symbol name used in the stack @@ -155,7 +145,7 @@ function getErrorSource( fileURLToPath(originalSourcePath) : originalSourcePath; const source = getOriginalSource( sourceMap.payload, - originalSourcePathNoScheme + originalSourcePath ); const lines = RegExpPrototypeSymbolSplit(/\r?\n/, source, originalLine + 1); const line = lines[originalLine]; @@ -178,28 +168,46 @@ function getErrorSource( function getOriginalSource(payload, originalSourcePath) { let source; - const originalSourcePathNoScheme = - StringPrototypeStartsWith(originalSourcePath, 'file://') ? - fileURLToPath(originalSourcePath) : originalSourcePath; + // payload.sources has been normalized to be an array of absolute urls. const sourceContentIndex = ArrayPrototypeIndexOf(payload.sources, originalSourcePath); if (payload.sourcesContent?.[sourceContentIndex]) { // First we check if the original source content was provided in the // source map itself: source = payload.sourcesContent[sourceContentIndex]; - } else { + } else if (StringPrototypeStartsWith(originalSourcePath, 'file://')) { // If no sourcesContent was found, attempt to load the original source // from disk: + debug(`read source of ${originalSourcePath} from filesystem`); + const originalSourcePathNoScheme = fileURLToPath(originalSourcePath); try { source = readFileSync(originalSourcePathNoScheme, 'utf8'); } catch (err) { debug(err); source = ''; } + } else { + source = ''; } return source; } +function getSourceMapErrorSource(fileName, lineNumber, columnNumber) { + const sm = findSourceMap(fileName); + if (sm === null) { + return; + } + const { + originalLine, + originalColumn, + originalSource, + } = sm.findEntry(lineNumber - 1, columnNumber); + const errorSource = getErrorSource(sm, originalSource, originalLine, originalColumn); + return errorSource; +} + +setGetSourceMapErrorSource(getSourceMapErrorSource); + module.exports = { prepareStackTrace, }; diff --git a/lib/internal/source_map/source_map_cache.js b/lib/internal/source_map/source_map_cache.js index c7770e7a6c733b..ba79540d837849 100644 --- a/lib/internal/source_map/source_map_cache.js +++ b/lib/internal/source_map/source_map_cache.js @@ -41,6 +41,8 @@ const esmSourceMapCache = new SafeMap(); // The generated sources is not mutable, so we can use a Map without memory concerns: const generatedSourceMapCache = new SafeMap(); const kLeadingProtocol = /^\w+:\/\//; +const kSourceMappingURLMagicComment = /\/[*/]#\s+sourceMappingURL=(?[^\s]+)/; +const kSourceURLMagicComment = /\/[*/]#\s+sourceURL=(?[^\s]+)/; const { fileURLToPath, pathToFileURL, URL } = require('internal/url'); let SourceMap; @@ -77,7 +79,22 @@ function setSourceMapsEnabled(val) { sourceMapsEnabled = val; } -function maybeCacheSourceMap(filename, content, cjsModuleInstance, isGeneratedSource) { +function extractSourceURLMagicComment(content) { + const matchSourceURL = RegExpPrototypeExec( + kSourceURLMagicComment, + content + ); + if (matchSourceURL === null) { + return null; + } + let sourceURL = matchSourceURL.groups.sourceURL; + if (sourceURL != null && RegExpPrototypeExec(kLeadingProtocol, sourceURL) === null) { + sourceURL = pathToFileURL(sourceURL).href; + } + return sourceURL; +} + +function maybeCacheSourceMap(filename, content, cjsModuleInstance, isGeneratedSource, sourceURL) { const sourceMapsEnabled = getSourceMapsEnabled(); if (!(process.env.NODE_V8_COVERAGE || sourceMapsEnabled)) return; try { @@ -87,10 +104,10 @@ function maybeCacheSourceMap(filename, content, cjsModuleInstance, isGeneratedSo debug(err); return; } - const match = RegExpPrototypeExec( - /\/[*/]#\s+sourceMappingURL=(?[^\s]+)/, - content, - ); + const match = RegExpPrototypeExec(kSourceMappingURLMagicComment, content); + if (sourceURL === undefined) { + sourceURL = extractSourceURLMagicComment(content); + } if (match) { const data = dataFromUrl(filename, match.groups.sourceMappingURL); const url = data ? null : match.groups.sourceMappingURL; @@ -99,22 +116,33 @@ function maybeCacheSourceMap(filename, content, cjsModuleInstance, isGeneratedSo filename, lineLengths: lineLengths(content), data, - url + url, + sourceURL, }); } else if (isGeneratedSource) { - generatedSourceMapCache.set(filename, { + const entry = { lineLengths: lineLengths(content), data, - url - }); + url, + sourceURL + }; + generatedSourceMapCache.set(filename, entry); + if (sourceURL) { + generatedSourceMapCache.set(sourceURL, entry); + } } else { // If there is no cjsModuleInstance and is not generated source assume we are in a // "modules/esm" context. - esmSourceMapCache.set(filename, { + const entry = { lineLengths: lineLengths(content), data, - url - }); + url, + sourceURL, + }; + esmSourceMapCache.set(filename, entry); + if (sourceURL) { + esmSourceMapCache.set(sourceURL, entry); + } } } } @@ -123,19 +151,12 @@ function maybeCacheGeneratedSourceMap(content) { const sourceMapsEnabled = getSourceMapsEnabled(); if (!(process.env.NODE_V8_COVERAGE || sourceMapsEnabled)) return; - const matchSourceURL = RegExpPrototypeExec( - /\/[*/]#\s+sourceURL=(?[^\s]+)/, - content - ); - if (matchSourceURL == null) { + const sourceURL = extractSourceURLMagicComment(content); + if (sourceURL === null) { return; } - let sourceURL = matchSourceURL.groups.sourceURL; - if (RegExpPrototypeExec(kLeadingProtocol, sourceURL) === null) { - sourceURL = pathToFileURL(sourceURL).href; - } try { - maybeCacheSourceMap(sourceURL, content, null, true); + maybeCacheSourceMap(sourceURL, content, null, true, sourceURL); } catch (err) { // This can happen if the filename is not a valid URL. // If we fail to cache the source map, we should not fail the whole process. @@ -254,33 +275,29 @@ function appendCJSCache(obj) { } } -function findSourceMap(sourceURL, isGenerated) { +function findSourceMap(sourceURL) { if (RegExpPrototypeExec(kLeadingProtocol, sourceURL) === null) { sourceURL = pathToFileURL(sourceURL).href; } if (!SourceMap) { SourceMap = require('internal/source_map/source_map').SourceMap; } - let sourceMap; - if (isGenerated) { - sourceMap = generatedSourceMapCache.get(sourceURL); - } else { - sourceMap = esmSourceMapCache.get(sourceURL); - if (sourceMap === undefined) { - for (const value of cjsSourceMapCache) { - const filename = ObjectGetValueSafe(value, 'filename'); - if (sourceURL === filename) { - sourceMap = { - data: ObjectGetValueSafe(value, 'data') - }; - } + let sourceMap = esmSourceMapCache.get(sourceURL) ?? generatedSourceMapCache.get(sourceURL); + if (sourceMap === undefined) { + for (const value of cjsSourceMapCache) { + const filename = ObjectGetValueSafe(value, 'filename'); + const cachedSourceURL = ObjectGetValueSafe(value, 'sourceURL'); + if (sourceURL === filename || sourceURL === cachedSourceURL) { + sourceMap = { + data: ObjectGetValueSafe(value, 'data') + }; } } } if (sourceMap && sourceMap.data) { return new SourceMap(sourceMap.data); } - return undefined; + return null; } module.exports = { diff --git a/src/env.h b/src/env.h index d38bc5338bc3e8..e17747fc97fdb8 100644 --- a/src/env.h +++ b/src/env.h @@ -525,6 +525,7 @@ class NoArrayBufferZeroFillScope { V(enhance_fatal_stack_after_inspector, v8::Function) \ V(enhance_fatal_stack_before_inspector, v8::Function) \ V(fs_use_promises_symbol, v8::Symbol) \ + V(get_source_map_error_source, v8::Function) \ V(host_import_module_dynamically_callback, v8::Function) \ V(host_initialize_import_meta_object_callback, v8::Function) \ V(http2session_on_altsvc_function, v8::Function) \ diff --git a/src/node_errors.cc b/src/node_errors.cc index 73467cf84e2d79..d529cf8b6c69d0 100644 --- a/src/node_errors.cc +++ b/src/node_errors.cc @@ -49,6 +49,40 @@ namespace per_process { static Mutex tty_mutex; } // namespace per_process +static std::string GetSourceMapErrorSource(Isolate* isolate, + Local context, + Local message, + bool* added_exception_line) { + v8::TryCatch try_catch(isolate); + HandleScope handle_scope(isolate); + Environment* env = Environment::GetCurrent(context); + + // The ScriptResourceName of the message may be different from the one we use + // to compile the script. V8 replaces it when it detects magic comments in + // the source texts. + Local script_resource_name = message->GetScriptResourceName(); + int linenum = message->GetLineNumber(context).FromJust(); + int columnum = message->GetStartColumn(context).FromJust(); + + Local argv[] = {script_resource_name, + v8::Int32::New(isolate, linenum), + v8::Int32::New(isolate, columnum)}; + MaybeLocal maybe_ret = env->get_source_map_error_source()->Call( + context, Undefined(isolate), arraysize(argv), argv); + Local ret; + if (!maybe_ret.ToLocal(&ret)) { + // Ignore the caught exceptions. + DCHECK(try_catch.HasCaught()); + return std::string(); + } + if (!ret->IsString()) { + return std::string(); + } + *added_exception_line = true; + node::Utf8Value error_source_utf8(isolate, ret.As()); + return *error_source_utf8; +} + static std::string GetErrorSource(Isolate* isolate, Local context, Local message, @@ -58,6 +92,10 @@ static std::string GetErrorSource(Isolate* isolate, std::string sourceline(*encoded_source, encoded_source.length()); *added_exception_line = false; + if (sourceline.find("node-do-not-add-exception-line") != std::string::npos) { + return sourceline; + } + // If source maps have been enabled, the exception line will instead be // added in the JavaScript context: Environment* env = Environment::GetCurrent(isolate); @@ -65,11 +103,9 @@ static std::string GetErrorSource(Isolate* isolate, !message->GetScriptOrigin().SourceMapUrl().IsEmpty() && !message->GetScriptOrigin().SourceMapUrl()->IsUndefined(); if (has_source_map_url && env != nullptr && env->source_maps_enabled()) { - return sourceline; - } - - if (sourceline.find("node-do-not-add-exception-line") != std::string::npos) { - return sourceline; + std::string source = GetSourceMapErrorSource( + isolate, context, message, added_exception_line); + return added_exception_line ? source : sourceline; } // Because of how node modules work, all scripts are wrapped with a @@ -869,6 +905,13 @@ static void SetSourceMapsEnabled(const FunctionCallbackInfo& args) { env->set_source_maps_enabled(args[0].As()->Value()); } +static void SetGetSourceMapErrorSource( + const FunctionCallbackInfo& args) { + Environment* env = Environment::GetCurrent(args); + CHECK(args[0]->IsFunction()); + env->set_get_source_map_error_source(args[0].As()); +} + static void SetMaybeCacheGeneratedSourceMap( const FunctionCallbackInfo& args) { Environment* env = Environment::GetCurrent(args); @@ -909,6 +952,7 @@ static void TriggerUncaughtException(const FunctionCallbackInfo& args) { void RegisterExternalReferences(ExternalReferenceRegistry* registry) { registry->Register(SetPrepareStackTraceCallback); + registry->Register(SetGetSourceMapErrorSource); registry->Register(SetSourceMapsEnabled); registry->Register(SetMaybeCacheGeneratedSourceMap); registry->Register(SetEnhanceStackForFatalException); @@ -923,6 +967,8 @@ void Initialize(Local target, Environment* env = Environment::GetCurrent(context); env->SetMethod( target, "setPrepareStackTraceCallback", SetPrepareStackTraceCallback); + env->SetMethod( + target, "setGetSourceMapErrorSource", SetGetSourceMapErrorSource); env->SetMethod(target, "setSourceMapsEnabled", SetSourceMapsEnabled); env->SetMethod(target, "setMaybeCacheGeneratedSourceMap", diff --git a/test/message/source_map_disabled_by_api.js b/test/message/source_map_disabled_by_api.js index 8405e4f3661cff..db55d24e1d5df8 100644 --- a/test/message/source_map_disabled_by_api.js +++ b/test/message/source_map_disabled_by_api.js @@ -17,4 +17,8 @@ delete require.cache[require // Re-enable. process.setSourceMapsEnabled(true); -require('../fixtures/source-map/enclosing-call-site-min.js'); +try { + require('../fixtures/source-map/enclosing-call-site-min.js'); +} catch (e) { + console.log(e); +} diff --git a/test/message/source_map_disabled_by_api.out b/test/message/source_map_disabled_by_api.out index 70979849795e11..f3f93758c1d272 100644 --- a/test/message/source_map_disabled_by_api.out +++ b/test/message/source_map_disabled_by_api.out @@ -9,10 +9,6 @@ Error: an error! at Module.load (node:internal/modules/cjs/loader:*) at Module._load (node:internal/modules/cjs/loader:*) at Module.require (node:internal/modules/cjs/loader:*) -*enclosing-call-site.js:16 - throw new Error('an error!') - ^ - Error: an error! at functionD (*enclosing-call-site.js:16:17) at functionC (*enclosing-call-site.js:10:3) @@ -24,5 +20,3 @@ Error: an error! at Module.load (node:internal/modules/cjs/loader:*) at Module._load (node:internal/modules/cjs/loader:*) at Module.require (node:internal/modules/cjs/loader:*) - -Node.js * diff --git a/test/message/source_map_enabled_by_api.js b/test/message/source_map_enabled_by_api.js index 3133bd26399fd4..29e0f9708903a8 100644 --- a/test/message/source_map_enabled_by_api.js +++ b/test/message/source_map_enabled_by_api.js @@ -14,4 +14,8 @@ delete require.cache[require process.setSourceMapsEnabled(false); -require('../fixtures/source-map/enclosing-call-site-min.js'); +try { + require('../fixtures/source-map/enclosing-call-site-min.js'); +} catch (e) { + console.log(e); +} diff --git a/test/message/source_map_enabled_by_api.out b/test/message/source_map_enabled_by_api.out index 9af1810020cf3f..97547436db091b 100644 --- a/test/message/source_map_enabled_by_api.out +++ b/test/message/source_map_enabled_by_api.out @@ -1,7 +1,3 @@ -*enclosing-call-site.js:16 - throw new Error('an error!') - ^ - Error: an error! at functionD (*enclosing-call-site.js:16:17) at functionC (*enclosing-call-site.js:10:3) @@ -13,10 +9,6 @@ Error: an error! at Module.load (node:internal/modules/cjs/loader:*) at Module._load (node:internal/modules/cjs/loader:*) at Module.require (node:internal/modules/cjs/loader:*) -*enclosing-call-site-min.js:1 -var functionA=function(){functionB()};function functionB(){functionC()}var functionC=function(){functionD()},functionD=function(){if(0