core: implement runtime flag to print warn on sync

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',

src/env-inl.h

@@ -176,6 +176,7 @@ inline Environment::Environment(v8::Local<v8::Context> 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);
 }

src/env.cc

@@ -0,0 +1,58 @@
+#include "env.h"
+#include "env-inl.h"
+#include "v8.h"
+#include <stdio.h>
+
+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<v8::StackTrace> 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<StackFrame> 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

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_;

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<String> 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);

src/node_crypto.cc

@@ -4630,6 +4630,7 @@ void PBKDF2(const FunctionCallbackInfo<Value>& args) {
                   EIO_PBKDF2,
                   EIO_PBKDF2After);
   } else {
+    env->PrintSyncTrace();
     Local<Value> argv[2];
     EIO_PBKDF2(req);
     EIO_PBKDF2After(req, argv);
@@ -4786,6 +4787,7 @@ void RandomBytes(const FunctionCallbackInfo<Value>& args) {
                   RandomBytesAfter);
     args.GetReturnValue().Set(obj);
   } else {
+    env->PrintSyncTrace();
     Local<Value> argv[2];
     RandomBytesWork(req->work_req());
     RandomBytesCheck(req, argv);

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__,                                         \

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);

src/spawn_sync.cc

@@ -349,7 +349,9 @@ void SyncProcessRunner::Initialize(Handle<Object> target,
 
 
 void SyncProcessRunner::Spawn(const FunctionCallbackInfo<Value>& args) {
-  SyncProcessRunner p(Environment::GetCurrent(args));
+  Environment* env = Environment::GetCurrent(args);
+  env->PrintSyncTrace();
+  SyncProcessRunner p(env);
   Local<Value> result = p.Run(args[0]);
   args.GetReturnValue().Set(result);
 }

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', ' ']));
+}
+