diff --git a/node.gyp b/node.gyp index c72b93b13868f4..70c9841a89a176 100644 --- a/node.gyp +++ b/node.gyp @@ -99,6 +99,7 @@ 'sources': [ 'src/debug-agent.cc', 'src/async-wrap.cc', + 'src/env.cc', 'src/fs_event_wrap.cc', 'src/cares_wrap.cc', 'src/handle_wrap.cc', diff --git a/src/env-inl.h b/src/env-inl.h index a0815acaccb926..0feefdb1e454c0 100644 --- a/src/env-inl.h +++ b/src/env-inl.h @@ -176,6 +176,7 @@ inline Environment::Environment(v8::Local context, using_abort_on_uncaught_exc_(false), using_asyncwrap_(false), printed_error_(false), + trace_sync_io_(false), debugger_agent_(this), context_(context->GetIsolate(), context) { // We'll be creating new objects so make sure we've entered the context. @@ -325,6 +326,10 @@ inline void Environment::set_printed_error(bool value) { printed_error_ = value; } +inline void Environment::set_trace_sync_io(bool value) { + trace_sync_io_ = value; +} + inline Environment* Environment::from_cares_timer_handle(uv_timer_t* handle) { return ContainerOf(&Environment::cares_timer_handle_, handle); } diff --git a/src/env.cc b/src/env.cc new file mode 100644 index 00000000000000..3deb4db09e6d92 --- /dev/null +++ b/src/env.cc @@ -0,0 +1,58 @@ +#include "env.h" +#include "env-inl.h" +#include "v8.h" +#include + +namespace node { + +using v8::HandleScope; +using v8::Local; +using v8::Message; +using v8::StackFrame; +using v8::StackTrace; + +void Environment::PrintSyncTrace() const { + if (!trace_sync_io_) + return; + + HandleScope handle_scope(isolate()); + Local stack = + StackTrace::CurrentStackTrace(isolate(), 10, StackTrace::kDetailed); + + fprintf(stderr, "WARNING: Detected use of sync API\n"); + + for (int i = 0; i < stack->GetFrameCount() - 1; i++) { + Local stack_frame = stack->GetFrame(i); + node::Utf8Value fn_name_s(isolate(), stack_frame->GetFunctionName()); + node::Utf8Value script_name(isolate(), stack_frame->GetScriptName()); + const int line_number = stack_frame->GetLineNumber(); + const int column = stack_frame->GetColumn(); + + if (stack_frame->IsEval()) { + if (stack_frame->GetScriptId() == Message::kNoScriptIdInfo) { + fprintf(stderr, " at [eval]:%i:%i\n", line_number, column); + } else { + fprintf(stderr, + " at [eval] (%s:%i:%i)\n", + *script_name, + line_number, + column); + } + break; + } + + if (fn_name_s.length() == 0) { + fprintf(stderr, " at %s:%i:%i\n", *script_name, line_number, column); + } else { + fprintf(stderr, + " at %s (%s:%i:%i)\n", + *fn_name_s, + *script_name, + line_number, + column); + } + } + fflush(stderr); +} + +} // namespace node diff --git a/src/env.h b/src/env.h index e327786e36b907..b53ff87fb13114 100644 --- a/src/env.h +++ b/src/env.h @@ -420,6 +420,9 @@ class Environment { inline bool printed_error() const; inline void set_printed_error(bool value); + void PrintSyncTrace() const; + inline void set_trace_sync_io(bool value); + inline void ThrowError(const char* errmsg); inline void ThrowTypeError(const char* errmsg); inline void ThrowRangeError(const char* errmsg); @@ -506,6 +509,7 @@ class Environment { bool using_abort_on_uncaught_exc_; bool using_asyncwrap_; bool printed_error_; + bool trace_sync_io_; debugger::Agent debugger_agent_; HandleWrapQueue handle_wrap_queue_; diff --git a/src/node.cc b/src/node.cc index a2c807eb715dcc..f47dd722056a8d 100644 --- a/src/node.cc +++ b/src/node.cc @@ -102,6 +102,8 @@ using v8::Promise; using v8::PromiseRejectMessage; using v8::PropertyCallbackInfo; using v8::SealHandleScope; +using v8::StackFrame; +using v8::StackTrace; using v8::String; using v8::TryCatch; using v8::Uint32; @@ -114,6 +116,7 @@ static bool force_repl = false; static bool trace_deprecation = false; static bool throw_deprecation = false; static bool abort_on_uncaught_exception = false; +static bool trace_sync_io = false; static const char* eval_string = nullptr; static unsigned int preload_module_count = 0; static const char** preload_modules = nullptr; @@ -2834,6 +2837,13 @@ void SetupProcessObject(Environment* env, READONLY_PROPERTY(process, "traceDeprecation", True(env->isolate())); } + // --trace-sync-io + if (trace_sync_io) { + READONLY_PROPERTY(process, "traceSyncIO", True(env->isolate())); + // Don't env->set_trace_sync_io(true) because it will be enabled + // after LoadEnvironment() has run. + } + size_t exec_path_len = 2 * PATH_MAX; char* exec_path = new char[exec_path_len]; Local exec_path_value; @@ -3060,6 +3070,8 @@ static void PrintHelp() { " --throw-deprecation throw an exception anytime a deprecated " "function is used\n" " --trace-deprecation show stack traces on deprecations\n" + " --trace-sync-io show stack trace when use of sync IO\n" + " is detected after the first tick\n" " --v8-options print v8 command line options\n" #if defined(NODE_HAVE_I18N_SUPPORT) " --icu-data-dir=dir set ICU data load path to dir\n" @@ -3180,6 +3192,8 @@ static void ParseArgs(int* argc, no_deprecation = true; } else if (strcmp(arg, "--trace-deprecation") == 0) { trace_deprecation = true; + } else if (strcmp(arg, "--trace-sync-io") == 0) { + trace_sync_io = true; } else if (strcmp(arg, "--throw-deprecation") == 0) { throw_deprecation = true; } else if (strcmp(arg, "--abort-on-uncaught-exception") == 0 || @@ -3887,6 +3901,8 @@ static void StartNodeInstance(void* arg) { LoadEnvironment(env); + env->set_trace_sync_io(trace_sync_io); + // Enable debugger if (instance_data->use_debug_agent()) EnableDebug(env); @@ -3911,6 +3927,8 @@ static void StartNodeInstance(void* arg) { } while (more == true); } + env->set_trace_sync_io(false); + int exit_code = EmitExit(env); if (instance_data->is_main()) instance_data->set_exit_code(exit_code); diff --git a/src/node_crypto.cc b/src/node_crypto.cc index e49545810d3f78..03dc7d61807d58 100644 --- a/src/node_crypto.cc +++ b/src/node_crypto.cc @@ -4630,6 +4630,7 @@ void PBKDF2(const FunctionCallbackInfo& args) { EIO_PBKDF2, EIO_PBKDF2After); } else { + env->PrintSyncTrace(); Local argv[2]; EIO_PBKDF2(req); EIO_PBKDF2After(req, argv); @@ -4786,6 +4787,7 @@ void RandomBytes(const FunctionCallbackInfo& args) { RandomBytesAfter); args.GetReturnValue().Set(obj); } else { + env->PrintSyncTrace(); Local argv[2]; RandomBytesWork(req->work_req()); RandomBytesCheck(req, argv); diff --git a/src/node_file.cc b/src/node_file.cc index 095710ef37e32b..71cf31829e859d 100644 --- a/src/node_file.cc +++ b/src/node_file.cc @@ -280,6 +280,7 @@ struct fs_req_wrap { #define SYNC_DEST_CALL(func, path, dest, ...) \ fs_req_wrap req_wrap; \ + env->PrintSyncTrace(); \ int err = uv_fs_ ## func(env->event_loop(), \ &req_wrap.req, \ __VA_ARGS__, \ diff --git a/src/node_zlib.cc b/src/node_zlib.cc index 884c244f9f0afc..58dfce397580ca 100644 --- a/src/node_zlib.cc +++ b/src/node_zlib.cc @@ -181,6 +181,7 @@ class ZCtx : public AsyncWrap { if (!async) { // sync version + ctx->env()->PrintSyncTrace(); Process(work_req); if (CheckError(ctx)) AfterSync(ctx, args); diff --git a/src/spawn_sync.cc b/src/spawn_sync.cc index 15e4fe8b103b0d..79428fcd73ccc5 100644 --- a/src/spawn_sync.cc +++ b/src/spawn_sync.cc @@ -349,7 +349,9 @@ void SyncProcessRunner::Initialize(Handle target, void SyncProcessRunner::Spawn(const FunctionCallbackInfo& args) { - SyncProcessRunner p(Environment::GetCurrent(args)); + Environment* env = Environment::GetCurrent(args); + env->PrintSyncTrace(); + SyncProcessRunner p(env); Local result = p.Run(args[0]); args.GetReturnValue().Set(result); } diff --git a/test/parallel/test-sync-io-option.js b/test/parallel/test-sync-io-option.js new file mode 100644 index 00000000000000..390710d265e7bf --- /dev/null +++ b/test/parallel/test-sync-io-option.js @@ -0,0 +1,44 @@ +'use strict'; + +const assert = require('assert'); +const spawn = require('child_process').spawn; + + +if (process.argv[2] === 'child') { + setImmediate(function() { + require('fs').readFileSync(__filename); + process.exit(); + }); + +} else { + (function runTest(flags) { + var execArgv = [flags.pop()]; + var args = [__filename, 'child']; + var child = spawn(process.execPath, execArgv.concat(args)); + var cntr = 0; + + child.stdout.on('data', function(chunk) { + throw new Error('UNREACHABLE'); + }); + + child.stderr.on('data', function(chunk) { + // Prints twice for --trace-sync-io. First for the require() and second + // for the fs operation. + if (/^WARNING[\s\S]*fs\.readFileSync/.test(chunk.toString())) + cntr++; + }); + + child.on('exit', function() { + if (execArgv[0] === '--trace-sync-io') + assert.equal(cntr, 2); + else if (execArgv[0] === ' ') + assert.equal(cntr, 0); + else + throw new Error('UNREACHABLE'); + + if (flags.length > 0) + setImmediate(runTest, flags); + }); + }(['--trace-sync-io', ' '])); +} +