src: trace fs async api

PR-URL: https://github.com/nodejs/node/pull/44057
Reviewed-By: James M Snell <jasnell@gmail.com>

2 files changed, 239 insertions, 27 deletions

diff --git a/src/node_dir.cc b/src/node_dir.cc
index c530da0cc3b..3a111fdabd3 100644
--- a/src/node_dir.cc
+++ b/src/node_dir.cc
@@ -42,18 +42,57 @@ using v8::Object;
 using v8::ObjectTemplate;
 using v8::Value;
 
+static const char* get_dir_func_name_by_type(uv_fs_type req_type) {
+  switch (req_type) {
+#define FS_TYPE_TO_NAME(type, name)                                            \
+  case UV_FS_##type:                                                           \
+    return name;
+    FS_TYPE_TO_NAME(OPENDIR, "opendir")
+    FS_TYPE_TO_NAME(READDIR, "readdir")
+    FS_TYPE_TO_NAME(CLOSEDIR, "closedir")
+#undef FS_TYPE_TO_NAME
+    default:
+      return "unknow";
+  }
+}
+
 #define TRACE_NAME(name) "fs_dir.sync." #name
 #define GET_TRACE_ENABLED                                                      \
-  (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED                                 \
-  (TRACING_CATEGORY_NODE2(fs_dir, sync)) != 0)
+  (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(                                \
+       TRACING_CATEGORY_NODE2(fs_dir, sync)) != 0)
 #define FS_DIR_SYNC_TRACE_BEGIN(syscall, ...)                                  \
   if (GET_TRACE_ENABLED)                                                       \
-  TRACE_EVENT_BEGIN(TRACING_CATEGORY_NODE2(fs_dir, sync), TRACE_NAME(syscall), \
-  ##__VA_ARGS__);
+    TRACE_EVENT_BEGIN(TRACING_CATEGORY_NODE2(fs_dir, sync),                    \
+                      TRACE_NAME(syscall),                                     \
+                      ##__VA_ARGS__);
 #define FS_DIR_SYNC_TRACE_END(syscall, ...)                                    \
   if (GET_TRACE_ENABLED)                                                       \
-  TRACE_EVENT_END(TRACING_CATEGORY_NODE2(fs_dir, sync), TRACE_NAME(syscall),   \
-  ##__VA_ARGS__);
+    TRACE_EVENT_END(TRACING_CATEGORY_NODE2(fs_dir, sync),                      \
+                    TRACE_NAME(syscall),                                       \
+                    ##__VA_ARGS__);
+
+#define FS_DIR_ASYNC_TRACE_BEGIN0(fs_type, id)                                 \
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(TRACING_CATEGORY_NODE2(fs_dir, async),     \
+                                    get_dir_func_name_by_type(fs_type),        \
+                                    id);
+#define FS_DIR_ASYNC_TRACE_END0(fs_type, id)                                   \
+  TRACE_EVENT_NESTABLE_ASYNC_END0(TRACING_CATEGORY_NODE2(fs_dir, async),       \
+                                  get_dir_func_name_by_type(fs_type),          \
+                                  id);
+
+#define FS_DIR_ASYNC_TRACE_BEGIN1(fs_type, id, name, value)                    \
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(TRACING_CATEGORY_NODE2(fs_dir, async),     \
+                                    get_dir_func_name_by_type(fs_type),        \
+                                    id,                                        \
+                                    name,                                      \
+                                    value);
+
+#define FS_DIR_ASYNC_TRACE_END1(fs_type, id, name, value)                      \
+  TRACE_EVENT_NESTABLE_ASYNC_END1(TRACING_CATEGORY_NODE2(fs_dir, async),       \
+                                  get_dir_func_name_by_type(fs_type),          \
+                                  id,                                          \
+                                  name,                                        \
+                                  value);
 
 DirHandle::DirHandle(Environment* env, Local<Object> obj, uv_dir_t* dir)
     : AsyncWrap(env, obj, AsyncWrap::PROVIDER_DIRHANDLE),
@@ -132,7 +171,8 @@ inline void DirHandle::GCClose() {
 void AfterClose(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_DIR_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (after.Proceed())
     req_wrap->Resolve(Undefined(req_wrap->env()->isolate()));
 }
@@ -151,6 +191,7 @@ void DirHandle::Close(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 0);
   if (req_wrap_async != nullptr) {  // close(req)
+    FS_DIR_ASYNC_TRACE_BEGIN0(UV_FS_CLOSEDIR, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "closedir", UTF8, AfterClose,
               uv_fs_closedir, dir->dir());
   } else {  // close(undefined, ctx)
@@ -196,7 +237,8 @@ static MaybeLocal<Array> DirentListToArray(
 static void AfterDirRead(uv_fs_t* req) {
   BaseObjectPtr<FSReqBase> req_wrap { FSReqBase::from_req(req) };
   FSReqAfterScope after(req_wrap.get(), req);
-
+  FS_DIR_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (!after.Proceed()) {
     return;
   }
@@ -256,6 +298,7 @@ void DirHandle::Read(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // dir.read(encoding, bufferSize, req)
+    FS_DIR_ASYNC_TRACE_BEGIN0(UV_FS_READDIR, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "readdir", encoding,
               AfterDirRead, uv_fs_readdir, dir->dir());
   } else {  // dir.read(encoding, bufferSize, undefined, ctx)
@@ -298,7 +341,8 @@ void DirHandle::Read(const FunctionCallbackInfo<Value>& args) {
 void AfterOpenDir(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_DIR_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (!after.Proceed()) {
     return;
   }
@@ -325,6 +369,8 @@ static void OpenDir(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // openDir(path, encoding, req)
+    FS_DIR_ASYNC_TRACE_BEGIN1(
+        UV_FS_OPENDIR, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "opendir", encoding, AfterOpenDir,
               uv_fs_opendir, *path);
   } else {  // openDir(path, encoding, undefined, ctx)
diff --git a/src/node_file.cc b/src/node_file.cc
index 21297acbcfa..5c9e1216ea4 100644
--- a/src/node_file.cc
+++ b/src/node_file.cc
@@ -111,18 +111,104 @@ inline int64_t GetOffset(Local<Value> value) {
   return IsSafeJsInt(value) ? value.As<Integer>()->Value() : -1;
 }
 
+static const char* get_fs_func_name_by_type(uv_fs_type req_type) {
+  switch (req_type) {
+#define FS_TYPE_TO_NAME(type, name)                                            \
+  case UV_FS_##type:                                                           \
+    return name;
+    FS_TYPE_TO_NAME(OPEN, "open")
+    FS_TYPE_TO_NAME(CLOSE, "close")
+    FS_TYPE_TO_NAME(READ, "read")
+    FS_TYPE_TO_NAME(WRITE, "write")
+    FS_TYPE_TO_NAME(SENDFILE, "sendfile")
+    FS_TYPE_TO_NAME(STAT, "stat")
+    FS_TYPE_TO_NAME(LSTAT, "lstat")
+    FS_TYPE_TO_NAME(FSTAT, "fstat")
+    FS_TYPE_TO_NAME(FTRUNCATE, "ftruncate")
+    FS_TYPE_TO_NAME(UTIME, "utime")
+    FS_TYPE_TO_NAME(FUTIME, "futime")
+    FS_TYPE_TO_NAME(ACCESS, "access")
+    FS_TYPE_TO_NAME(CHMOD, "chmod")
+    FS_TYPE_TO_NAME(FCHMOD, "fchmod")
+    FS_TYPE_TO_NAME(FSYNC, "fsync")
+    FS_TYPE_TO_NAME(FDATASYNC, "fdatasync")
+    FS_TYPE_TO_NAME(UNLINK, "unlink")
+    FS_TYPE_TO_NAME(RMDIR, "rmdir")
+    FS_TYPE_TO_NAME(MKDIR, "mkdir")
+    FS_TYPE_TO_NAME(MKDTEMP, "mkdtemp")
+    FS_TYPE_TO_NAME(RENAME, "rename")
+    FS_TYPE_TO_NAME(SCANDIR, "scandir")
+    FS_TYPE_TO_NAME(LINK, "link")
+    FS_TYPE_TO_NAME(SYMLINK, "symlink")
+    FS_TYPE_TO_NAME(READLINK, "readlink")
+    FS_TYPE_TO_NAME(CHOWN, "chown")
+    FS_TYPE_TO_NAME(FCHOWN, "fchown")
+    FS_TYPE_TO_NAME(REALPATH, "realpath")
+    FS_TYPE_TO_NAME(COPYFILE, "copyfile")
+    FS_TYPE_TO_NAME(LCHOWN, "lchown")
+    FS_TYPE_TO_NAME(STATFS, "statfs")
+    FS_TYPE_TO_NAME(MKSTEMP, "mkstemp")
+    FS_TYPE_TO_NAME(LUTIME, "lutime")
+#undef FS_TYPE_TO_NAME
+    default:
+      return "unknow";
+  }
+}
+
 #define TRACE_NAME(name) "fs.sync." #name
-#define GET_TRACE_ENABLED                                                  \
-  (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED                             \
-  (TRACING_CATEGORY_NODE2(fs, sync)) != 0)
-#define FS_SYNC_TRACE_BEGIN(syscall, ...)                                  \
-  if (GET_TRACE_ENABLED)                                                   \
-  TRACE_EVENT_BEGIN(TRACING_CATEGORY_NODE2(fs, sync), TRACE_NAME(syscall), \
-  ##__VA_ARGS__);
-#define FS_SYNC_TRACE_END(syscall, ...)                                    \
-  if (GET_TRACE_ENABLED)                                                   \
-  TRACE_EVENT_END(TRACING_CATEGORY_NODE2(fs, sync), TRACE_NAME(syscall),   \
-  ##__VA_ARGS__);
+#define GET_TRACE_ENABLED                                                      \
+  (*TRACE_EVENT_API_GET_CATEGORY_GROUP_ENABLED(                                \
+       TRACING_CATEGORY_NODE2(fs, sync)) != 0)
+#define FS_SYNC_TRACE_BEGIN(syscall, ...)                                      \
+  if (GET_TRACE_ENABLED)                                                       \
+    TRACE_EVENT_BEGIN(                                                         \
+        TRACING_CATEGORY_NODE2(fs, sync), TRACE_NAME(syscall), ##__VA_ARGS__);
+#define FS_SYNC_TRACE_END(syscall, ...)                                        \
+  if (GET_TRACE_ENABLED)                                                       \
+    TRACE_EVENT_END(                                                           \
+        TRACING_CATEGORY_NODE2(fs, sync), TRACE_NAME(syscall), ##__VA_ARGS__);
+
+#define FS_ASYNC_TRACE_BEGIN0(fs_type, id)                                     \
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN0(TRACING_CATEGORY_NODE2(fs, async),         \
+                                    get_fs_func_name_by_type(fs_type),         \
+                                    id);
+
+#define FS_ASYNC_TRACE_END0(fs_type, id)                                       \
+  TRACE_EVENT_NESTABLE_ASYNC_END0(TRACING_CATEGORY_NODE2(fs, async),           \
+                                  get_fs_func_name_by_type(fs_type),           \
+                                  id);
+
+#define FS_ASYNC_TRACE_BEGIN1(fs_type, id, name, value)                        \
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(TRACING_CATEGORY_NODE2(fs, async),         \
+                                    get_fs_func_name_by_type(fs_type),         \
+                                    id,                                        \
+                                    name,                                      \
+                                    value);
+
+#define FS_ASYNC_TRACE_END1(fs_type, id, name, value)                          \
+  TRACE_EVENT_NESTABLE_ASYNC_END1(TRACING_CATEGORY_NODE2(fs, async),           \
+                                  get_fs_func_name_by_type(fs_type),           \
+                                  id,                                          \
+                                  name,                                        \
+                                  value);
+
+#define FS_ASYNC_TRACE_BEGIN2(fs_type, id, name1, value1, name2, value2)       \
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN2(TRACING_CATEGORY_NODE2(fs, async),         \
+                                    get_fs_func_name_by_type(fs_type),         \
+                                    id,                                        \
+                                    name1,                                     \
+                                    value1,                                    \
+                                    name2,                                     \
+                                    value2);
+
+#define FS_ASYNC_TRACE_END2(fs_type, id, name1, value1, name2, value2)         \
+  TRACE_EVENT_NESTABLE_ASYNC_END2(TRACING_CATEGORY_NODE2(fs, async),           \
+                                  get_fs_func_name_by_type(fs_type),           \
+                                  id,                                          \
+                                  name1,                                       \
+                                  value1,                                      \
+                                  name2,                                       \
+                                  value2);
 
 // We sometimes need to convert a C++ lambda function to a raw C-style function.
 // This is helpful, because ReqWrap::Dispatch() does not recognize lambda
@@ -665,7 +751,8 @@ bool FSReqAfterScope::Proceed() {
 void AfterNoArgs(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (after.Proceed())
     req_wrap->Resolve(Undefined(req_wrap->env()->isolate()));
 }
@@ -673,7 +760,8 @@ void AfterNoArgs(uv_fs_t* req) {
 void AfterStat(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (after.Proceed()) {
     req_wrap->ResolveStat(&req->statbuf);
   }
@@ -682,7 +770,8 @@ void AfterStat(uv_fs_t* req) {
 void AfterInteger(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   int result = static_cast<int>(req->result);
   if (result >= 0 && req_wrap->is_plain_open())
     req_wrap->env()->AddUnmanagedFd(result);
@@ -694,7 +783,8 @@ void AfterInteger(uv_fs_t* req) {
 void AfterOpenFileHandle(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (after.Proceed()) {
     FileHandle* fd = FileHandle::New(req_wrap->binding_data(),
                                      static_cast<int>(req->result));
@@ -719,6 +809,8 @@ void FromNamespacedPath(std::string* path) {
 void AfterMkdirp(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (after.Proceed()) {
     std::string first_path(req_wrap->continuation_data()->first_path());
     if (first_path.empty())
@@ -738,7 +830,8 @@ void AfterMkdirp(uv_fs_t* req) {
 void AfterStringPath(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   MaybeLocal<Value> link;
   Local<Value> error;
 
@@ -757,7 +850,8 @@ void AfterStringPath(uv_fs_t* req) {
 void AfterStringPtr(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   MaybeLocal<Value> link;
   Local<Value> error;
 
@@ -776,7 +870,8 @@ void AfterStringPtr(uv_fs_t* req) {
 void AfterScanDir(uv_fs_t* req) {
   FSReqBase* req_wrap = FSReqBase::from_req(req);
   FSReqAfterScope after(req_wrap, req);
-
+  FS_ASYNC_TRACE_END1(
+      req->fs_type, req_wrap, "result", static_cast<int>(req->result))
   if (!after.Proceed()) {
     return;
   }
@@ -837,6 +932,8 @@ void Access(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // access(path, mode, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_ACCESS, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "access", UTF8, AfterNoArgs,
               uv_fs_access, *path, mode);
   } else {  // access(path, mode, undefined, ctx)
@@ -861,6 +958,7 @@ void Close(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 1);
   if (req_wrap_async != nullptr) {  // close(fd, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_CLOSE, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "close", UTF8, AfterNoArgs,
               uv_fs_close, fd);
   } else {  // close(fd, undefined, ctx)
@@ -1002,6 +1100,8 @@ static void Stat(const FunctionCallbackInfo<Value>& args) {
   bool use_bigint = args[1]->IsTrue();
   FSReqBase* req_wrap_async = GetReqWrap(args, 2, use_bigint);
   if (req_wrap_async != nullptr) {  // stat(path, use_bigint, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_STAT, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "stat", UTF8, AfterStat,
               uv_fs_stat, *path);
   } else {  // stat(path, use_bigint, undefined, ctx)
@@ -1033,6 +1133,8 @@ static void LStat(const FunctionCallbackInfo<Value>& args) {
   bool use_bigint = args[1]->IsTrue();
   FSReqBase* req_wrap_async = GetReqWrap(args, 2, use_bigint);
   if (req_wrap_async != nullptr) {  // lstat(path, use_bigint, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_LSTAT, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "lstat", UTF8, AfterStat,
               uv_fs_lstat, *path);
   } else {  // lstat(path, use_bigint, undefined, ctx)
@@ -1065,6 +1167,7 @@ static void FStat(const FunctionCallbackInfo<Value>& args) {
   bool use_bigint = args[1]->IsTrue();
   FSReqBase* req_wrap_async = GetReqWrap(args, 2, use_bigint);
   if (req_wrap_async != nullptr) {  // fstat(fd, use_bigint, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FSTAT, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "fstat", UTF8, AfterStat,
               uv_fs_fstat, fd);
   } else {  // fstat(fd, use_bigint, undefined, ctx)
@@ -1100,6 +1203,12 @@ static void Symlink(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // symlink(target, path, flags, req)
+    FS_ASYNC_TRACE_BEGIN2(UV_FS_SYMLINK,
+                          req_wrap_async,
+                          "target",
+                          TRACE_STR_COPY(*target),
+                          "path",
+                          TRACE_STR_COPY(*path))
     AsyncDestCall(env, req_wrap_async, args, "symlink", *path, path.length(),
                   UTF8, AfterNoArgs, uv_fs_symlink, *target, *path, flags);
   } else {  // symlink(target, path, flags, undefinec, ctx)
@@ -1127,6 +1236,12 @@ static void Link(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // link(src, dest, req)
+    FS_ASYNC_TRACE_BEGIN2(UV_FS_LINK,
+                          req_wrap_async,
+                          "src",
+                          TRACE_STR_COPY(*src),
+                          "dest",
+                          TRACE_STR_COPY(*dest))
     AsyncDestCall(env, req_wrap_async, args, "link", *dest, dest.length(), UTF8,
                   AfterNoArgs, uv_fs_link, *src, *dest);
   } else {  // link(src, dest)
@@ -1153,6 +1268,8 @@ static void ReadLink(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // readlink(path, encoding, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_READLINK, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "readlink", encoding, AfterStringPtr,
               uv_fs_readlink, *path);
   } else {
@@ -1196,6 +1313,12 @@ static void Rename(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN2(UV_FS_RENAME,
+                          req_wrap_async,
+                          "old_path",
+                          TRACE_STR_COPY(*old_path),
+                          "new_path",
+                          TRACE_STR_COPY(*new_path))
     AsyncDestCall(env, req_wrap_async, args, "rename", *new_path,
                   new_path.length(), UTF8, AfterNoArgs, uv_fs_rename,
                   *old_path, *new_path);
@@ -1223,6 +1346,7 @@ static void FTruncate(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FTRUNCATE, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "ftruncate", UTF8, AfterNoArgs,
               uv_fs_ftruncate, fd, len);
   } else {
@@ -1246,6 +1370,7 @@ static void Fdatasync(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 1);
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FDATASYNC, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "fdatasync", UTF8, AfterNoArgs,
               uv_fs_fdatasync, fd);
   } else {
@@ -1268,6 +1393,7 @@ static void Fsync(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 1);
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FSYNC, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "fsync", UTF8, AfterNoArgs,
               uv_fs_fsync, fd);
   } else {
@@ -1290,6 +1416,8 @@ static void Unlink(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 1);
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_UNLINK, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "unlink", UTF8, AfterNoArgs,
               uv_fs_unlink, *path);
   } else {
@@ -1312,6 +1440,8 @@ static void RMDir(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 1);  // rmdir(path, req)
   if (req_wrap_async != nullptr) {
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_RMDIR, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "rmdir", UTF8, AfterNoArgs,
               uv_fs_rmdir, *path);
   } else {  // rmdir(path, undefined, ctx)
@@ -1523,6 +1653,8 @@ static void MKDir(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // mkdir(path, mode, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_UNLINK, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "mkdir", UTF8,
               mkdirp ? AfterMkdirp : AfterNoArgs,
               mkdirp ? MKDirpAsync : uv_fs_mkdir, *path, mode);
@@ -1569,6 +1701,8 @@ static void RealPath(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // realpath(path, encoding, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_REALPATH, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "realpath", encoding, AfterStringPtr,
               uv_fs_realpath, *path);
   } else {  // realpath(path, encoding, undefined, ctx)
@@ -1616,6 +1750,8 @@ static void ReadDir(const FunctionCallbackInfo<Value>& args) {
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // readdir(path, encoding, withTypes, req)
     req_wrap_async->set_with_file_types(with_types);
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_SCANDIR, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env,
               req_wrap_async,
               args,
@@ -1707,6 +1843,8 @@ static void Open(const FunctionCallbackInfo<Value>& args) {
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // open(path, flags, mode, req)
     req_wrap_async->set_is_plain_open(true);
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_OPEN, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "open", UTF8, AfterInteger,
               uv_fs_open, *path, flags, mode);
   } else {  // open(path, flags, mode, undefined, ctx)
@@ -1740,6 +1878,8 @@ static void OpenFileHandle(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // openFileHandle(path, flags, mode, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_OPEN, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "open", UTF8, AfterOpenFileHandle,
               uv_fs_open, *path, flags, mode);
   } else {  // openFileHandle(path, flags, mode, undefined, ctx)
@@ -1776,6 +1916,12 @@ static void CopyFile(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // copyFile(src, dest, flags, req)
+    FS_ASYNC_TRACE_BEGIN2(UV_FS_COPYFILE,
+                          req_wrap_async,
+                          "src",
+                          TRACE_STR_COPY(*src),
+                          "dest",
+                          TRACE_STR_COPY(*dest))
     AsyncDestCall(env, req_wrap_async, args, "copyfile",
                   *dest, dest.length(), UTF8, AfterNoArgs,
                   uv_fs_copyfile, *src, *dest, flags);
@@ -1832,6 +1978,7 @@ static void WriteBuffer(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 5);
   if (req_wrap_async != nullptr) {  // write(fd, buffer, off, len, pos, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_WRITE, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "write", UTF8, AfterInteger,
               uv_fs_write, fd, &uvbuf, 1, pos);
   } else {  // write(fd, buffer, off, len, pos, undefined, ctx)
@@ -1877,6 +2024,7 @@ static void WriteBuffers(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // writeBuffers(fd, chunks, pos, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_WRITE, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "write", UTF8, AfterInteger,
               uv_fs_write, fd, *iovs, iovs.length(), pos);
   } else {  // writeBuffers(fd, chunks, pos, undefined, ctx)
@@ -1950,6 +2098,7 @@ static void WriteString(const FunctionCallbackInfo<Value>& args) {
     len = StringBytes::Write(isolate, *stack_buffer, len, args[1], enc);
     stack_buffer.SetLengthAndZeroTerminate(len);
     uv_buf_t uvbuf = uv_buf_init(*stack_buffer, len);
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_WRITE, req_wrap_async)
     int err = req_wrap_async->Dispatch(uv_fs_write,
                                        fd,
                                        &uvbuf,
@@ -2035,6 +2184,7 @@ static void Read(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 5);
   if (req_wrap_async != nullptr) {  // read(fd, buffer, offset, len, pos, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_READ, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "read", UTF8, AfterInteger,
               uv_fs_read, fd, &uvbuf, 1, pos);
   } else {  // read(fd, buffer, offset, len, pos, undefined, ctx)
@@ -2081,6 +2231,7 @@ static void ReadBuffers(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // readBuffers(fd, buffers, pos, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_READ, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "read", UTF8, AfterInteger,
               uv_fs_read, fd, *iovs, iovs.length(), pos);
   } else {  // readBuffers(fd, buffers, undefined, ctx)
@@ -2112,6 +2263,8 @@ static void Chmod(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // chmod(path, mode, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_CHMOD, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "chmod", UTF8, AfterNoArgs,
               uv_fs_chmod, *path, mode);
   } else {  // chmod(path, mode, undefined, ctx)
@@ -2142,6 +2295,7 @@ static void FChmod(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // fchmod(fd, mode, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FCHMOD, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "fchmod", UTF8, AfterNoArgs,
               uv_fs_fchmod, fd, mode);
   } else {  // fchmod(fd, mode, undefined, ctx)
@@ -2175,6 +2329,8 @@ static void Chown(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // chown(path, uid, gid, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_CHOWN, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "chown", UTF8, AfterNoArgs,
               uv_fs_chown, *path, uid, gid);
   } else {  // chown(path, uid, gid, undefined, ctx)
@@ -2208,6 +2364,7 @@ static void FChown(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // fchown(fd, uid, gid, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FCHOWN, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "fchown", UTF8, AfterNoArgs,
               uv_fs_fchown, fd, uid, gid);
   } else {  // fchown(fd, uid, gid, undefined, ctx)
@@ -2238,6 +2395,8 @@ static void LChown(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // lchown(path, uid, gid, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_LCHOWN, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "lchown", UTF8, AfterNoArgs,
               uv_fs_lchown, *path, uid, gid);
   } else {  // lchown(path, uid, gid, undefined, ctx)
@@ -2268,6 +2427,8 @@ static void UTimes(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // utimes(path, atime, mtime, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_UTIME, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "utime", UTF8, AfterNoArgs,
               uv_fs_utime, *path, atime, mtime);
   } else {  // utimes(path, atime, mtime, undefined, ctx)
@@ -2297,6 +2458,7 @@ static void FUTimes(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // futimes(fd, atime, mtime, req)
+    FS_ASYNC_TRACE_BEGIN0(UV_FS_FUTIME, req_wrap_async)
     AsyncCall(env, req_wrap_async, args, "futime", UTF8, AfterNoArgs,
               uv_fs_futime, fd, atime, mtime);
   } else {  // futimes(fd, atime, mtime, undefined, ctx)
@@ -2326,6 +2488,8 @@ static void LUTimes(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 3);
   if (req_wrap_async != nullptr) {  // lutimes(path, atime, mtime, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_LUTIME, req_wrap_async, "path", TRACE_STR_COPY(*path))
     AsyncCall(env, req_wrap_async, args, "lutime", UTF8, AfterNoArgs,
               uv_fs_lutime, *path, atime, mtime);
   } else {  // lutimes(path, atime, mtime, undefined, ctx)
@@ -2352,6 +2516,8 @@ static void Mkdtemp(const FunctionCallbackInfo<Value>& args) {
 
   FSReqBase* req_wrap_async = GetReqWrap(args, 2);
   if (req_wrap_async != nullptr) {  // mkdtemp(tmpl, encoding, req)
+    FS_ASYNC_TRACE_BEGIN1(
+        UV_FS_MKDTEMP, req_wrap_async, "path", TRACE_STR_COPY(*tmpl))
     AsyncCall(env, req_wrap_async, args, "mkdtemp", encoding, AfterStringPath,
               uv_fs_mkdtemp, *tmpl);
   } else {  // mkdtemp(tmpl, encoding, undefined, ctx)