Skip to content

src: add sync trace to fs #19649

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 1 commit into from
Closed

src: add sync trace to fs #19649

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
77 changes: 76 additions & 1 deletion src/node_file.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
#include "node_internals.h"
#include "node_stat_watcher.h"
#include "node_file.h"
#include "tracing/trace_event.h"

#include "req_wrap-inl.h"
#include "stream_base-inl.h"
Expand Down Expand Up @@ -75,6 +76,18 @@ using v8::Value;
#endif

#define GET_OFFSET(a) ((a)->IsNumber() ? (a).As<Integer>()->Value() : -1)
#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__);

// The FileHandle object wraps a file descriptor and will close it on garbage
// collection if necessary. If that happens, a process warning will be
Expand Down Expand Up @@ -316,7 +329,7 @@ int FileHandle::ReadStart() {

// ReadStart() checks whether current_read_ is set to determine whether
// a read is in progress. Moving it into a local variable makes sure that
// the ReadStart() call below doesn’t think we’re still actively reading.
// the ReadStart() call below doesn't think we're still actively reading.
std::unique_ptr<FileHandleReadWrap> read_wrap =
std::move(handle->current_read_);

Expand Down Expand Up @@ -683,7 +696,9 @@ void Access(const FunctionCallbackInfo<Value>& args) {
} else { // access(path, mode, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(access);
SyncCall(env, args[3], &req_wrap_sync, "access", uv_fs_access, *path, mode);
FS_SYNC_TRACE_END(access);
}
}

Expand All @@ -704,7 +719,9 @@ void Close(const FunctionCallbackInfo<Value>& args) {
} else { // close(fd, undefined, ctx)
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(close);
SyncCall(env, args[2], &req_wrap_sync, "close", uv_fs_close, fd);
FS_SYNC_TRACE_END(close);
}
}

Expand Down Expand Up @@ -812,7 +829,9 @@ static void Stat(const FunctionCallbackInfo<Value>& args) {
} else { // stat(path, undefined, ctx)
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(stat);
int err = SyncCall(env, args[2], &req_wrap_sync, "stat", uv_fs_stat, *path);
FS_SYNC_TRACE_END(stat);
if (err == 0) {
node::FillGlobalStatsArray(env,
static_cast<const uv_stat_t*>(req_wrap_sync.req.ptr));
Expand All @@ -836,8 +855,10 @@ static void LStat(const FunctionCallbackInfo<Value>& args) {
} else { // lstat(path, undefined, ctx)
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(lstat);
int err = SyncCall(env, args[2], &req_wrap_sync, "lstat", uv_fs_lstat,
*path);
FS_SYNC_TRACE_END(lstat);
if (err == 0) {
node::FillGlobalStatsArray(env,
static_cast<const uv_stat_t*>(req_wrap_sync.req.ptr));
Expand All @@ -861,7 +882,9 @@ static void FStat(const FunctionCallbackInfo<Value>& args) {
} else { // fstat(fd, undefined, ctx)
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(fstat);
int err = SyncCall(env, args[2], &req_wrap_sync, "fstat", uv_fs_fstat, fd);
FS_SYNC_TRACE_END(fstat);
if (err == 0) {
node::FillGlobalStatsArray(env,
static_cast<const uv_stat_t*>(req_wrap_sync.req.ptr));
Expand Down Expand Up @@ -890,8 +913,10 @@ static void Symlink(const FunctionCallbackInfo<Value>& args) {
} else { // symlink(target, path, flags, undefinec, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(symlink);
SyncCall(env, args[4], &req_wrap_sync, "symlink",
uv_fs_symlink, *target, *path, flags);
FS_SYNC_TRACE_END(symlink);
}
}

Expand All @@ -914,8 +939,10 @@ static void Link(const FunctionCallbackInfo<Value>& args) {
} else { // link(src, dest)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(link);
SyncCall(env, args[3], &req_wrap_sync, "link",
uv_fs_link, *src, *dest);
FS_SYNC_TRACE_END(link);
}
}

Expand All @@ -937,8 +964,10 @@ static void ReadLink(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(readlink);
int err = SyncCall(env, args[3], &req_wrap_sync, "readlink",
uv_fs_readlink, *path);
FS_SYNC_TRACE_END(readlink);
if (err < 0) {
return; // syscall failed, no need to continue, error info is in ctx
}
Expand Down Expand Up @@ -978,8 +1007,10 @@ static void Rename(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(rename);
SyncCall(env, args[3], &req_wrap_sync, "rename", uv_fs_rename,
*old_path, *new_path);
FS_SYNC_TRACE_END(rename);
}
}

Expand All @@ -1002,8 +1033,10 @@ static void FTruncate(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(ftruncate);
SyncCall(env, args[3], &req_wrap_sync, "ftruncate", uv_fs_ftruncate, fd,
len);
FS_SYNC_TRACE_END(ftruncate);
}
}

Expand All @@ -1023,7 +1056,9 @@ static void Fdatasync(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(fdatasync);
SyncCall(env, args[2], &req_wrap_sync, "fdatasync", uv_fs_fdatasync, fd);
FS_SYNC_TRACE_END(fdatasync);
}
}

Expand All @@ -1043,7 +1078,9 @@ static void Fsync(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(fsync);
SyncCall(env, args[2], &req_wrap_sync, "fsync", uv_fs_fsync, fd);
FS_SYNC_TRACE_END(fsync);
}
}

Expand All @@ -1063,7 +1100,9 @@ static void Unlink(const FunctionCallbackInfo<Value>& args) {
} else {
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(unlink);
SyncCall(env, args[2], &req_wrap_sync, "unlink", uv_fs_unlink, *path);
FS_SYNC_TRACE_END(unlink);
}
}

Expand All @@ -1083,8 +1122,10 @@ static void RMDir(const FunctionCallbackInfo<Value>& args) {
} else { // rmdir(path, undefined, ctx)
CHECK_EQ(argc, 3);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(rmdir);
SyncCall(env, args[2], &req_wrap_sync, "rmdir",
uv_fs_rmdir, *path);
FS_SYNC_TRACE_END(rmdir);
}
}

Expand All @@ -1107,8 +1148,10 @@ static void MKDir(const FunctionCallbackInfo<Value>& args) {
} else { // mkdir(path, mode, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(mkdir);
SyncCall(env, args[3], &req_wrap_sync, "mkdir",
uv_fs_mkdir, *path, mode);
FS_SYNC_TRACE_END(mkdir);
}
}

Expand All @@ -1130,8 +1173,10 @@ static void RealPath(const FunctionCallbackInfo<Value>& args) {
} else { // realpath(path, encoding, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(realpath);
int err = SyncCall(env, args[3], &req_wrap_sync, "realpath",
uv_fs_realpath, *path);
FS_SYNC_TRACE_END(realpath);
if (err < 0) {
return; // syscall failed, no need to continue, error info is in ctx
}
Expand Down Expand Up @@ -1171,8 +1216,10 @@ static void ReadDir(const FunctionCallbackInfo<Value>& args) {
} else { // readdir(path, encoding, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(readdir);
int err = SyncCall(env, args[3], &req_wrap_sync, "scandir",
uv_fs_scandir, *path, 0 /*flags*/);
FS_SYNC_TRACE_END(readdir);
if (err < 0) {
return; // syscall failed, no need to continue, error info is in ctx
}
Expand Down Expand Up @@ -1255,8 +1302,10 @@ static void Open(const FunctionCallbackInfo<Value>& args) {
} else { // open(path, flags, mode, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(open);
int result = SyncCall(env, args[4], &req_wrap_sync, "open",
uv_fs_open, *path, flags, mode);
FS_SYNC_TRACE_END(open);
args.GetReturnValue().Set(result);
}
}
Expand All @@ -1283,8 +1332,10 @@ static void OpenFileHandle(const FunctionCallbackInfo<Value>& args) {
} else { // openFileHandle(path, flags, mode, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(open);
int result = SyncCall(env, args[4], &req_wrap_sync, "open",
uv_fs_open, *path, flags, mode);
FS_SYNC_TRACE_END(open);
if (result < 0) {
return; // syscall failed, no need to continue, error info is in ctx
}
Expand Down Expand Up @@ -1317,8 +1368,10 @@ static void CopyFile(const FunctionCallbackInfo<Value>& args) {
} else { // copyFile(src, dest, flags, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(copyfile);
SyncCall(env, args[4], &req_wrap_sync, "copyfile",
uv_fs_copyfile, *src, *dest, flags);
FS_SYNC_TRACE_END(copyfile);
}
}

Expand Down Expand Up @@ -1368,8 +1421,10 @@ static void WriteBuffer(const FunctionCallbackInfo<Value>& args) {
} else { // write(fd, buffer, off, len, pos, undefined, ctx)
CHECK_EQ(argc, 7);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(write);
int bytesWritten = SyncCall(env, args[6], &req_wrap_sync, "write",
uv_fs_write, fd, &uvbuf, 1, pos);
FS_SYNC_TRACE_END(write, "bytesWritten", bytesWritten);
args.GetReturnValue().Set(bytesWritten);
}
}
Expand Down Expand Up @@ -1411,8 +1466,10 @@ static void WriteBuffers(const FunctionCallbackInfo<Value>& args) {
} else { // writeBuffers(fd, chunks, pos, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(write);
int bytesWritten = SyncCall(env, args[4], &req_wrap_sync, "write",
uv_fs_write, fd, *iovs, iovs.length(), pos);
FS_SYNC_TRACE_END(write, "bytesWritten", bytesWritten);
args.GetReturnValue().Set(bytesWritten);
}
}
Expand Down Expand Up @@ -1503,8 +1560,10 @@ static void WriteString(const FunctionCallbackInfo<Value>& args) {
buf = *stack_buffer;
}
uv_buf_t uvbuf = uv_buf_init(buf, len);
FS_SYNC_TRACE_BEGIN(write);
int bytesWritten = SyncCall(env, args[5], &req_wrap_sync, "write",
uv_fs_write, fd, &uvbuf, 1, pos);
FS_SYNC_TRACE_END(write, "bytesWritten", bytesWritten);
args.GetReturnValue().Set(bytesWritten);
}
}
Expand Down Expand Up @@ -1556,8 +1615,10 @@ static void Read(const FunctionCallbackInfo<Value>& args) {
} else { // read(fd, buffer, offset, len, pos, undefined, ctx)
CHECK_EQ(argc, 7);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(read);
const int bytesRead = SyncCall(env, args[6], &req_wrap_sync, "read",
uv_fs_read, fd, &uvbuf, 1, pos);
FS_SYNC_TRACE_END(read, "bytesRead", bytesRead);
args.GetReturnValue().Set(bytesRead);
}
}
Expand Down Expand Up @@ -1585,8 +1646,10 @@ static void Chmod(const FunctionCallbackInfo<Value>& args) {
} else { // chmod(path, mode, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(chmod);
SyncCall(env, args[3], &req_wrap_sync, "chmod",
uv_fs_chmod, *path, mode);
FS_SYNC_TRACE_END(chmod);
}
}

Expand All @@ -1613,8 +1676,10 @@ static void FChmod(const FunctionCallbackInfo<Value>& args) {
} else { // fchmod(fd, mode, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(fchmod);
SyncCall(env, args[3], &req_wrap_sync, "fchmod",
uv_fs_fchmod, fd, mode);
FS_SYNC_TRACE_END(fchmod);
}
}

Expand Down Expand Up @@ -1644,8 +1709,10 @@ static void Chown(const FunctionCallbackInfo<Value>& args) {
} else { // chown(path, uid, gid, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(chown);
SyncCall(env, args[4], &req_wrap_sync, "chown",
uv_fs_chown, *path, uid, gid);
FS_SYNC_TRACE_END(chown);
}
}

Expand Down Expand Up @@ -1675,8 +1742,10 @@ static void FChown(const FunctionCallbackInfo<Value>& args) {
} else { // fchown(fd, uid, gid, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(fchown);
SyncCall(env, args[4], &req_wrap_sync, "fchown",
uv_fs_fchown, fd, uid, gid);
FS_SYNC_TRACE_END(fchown);
}
}

Expand All @@ -1703,8 +1772,10 @@ static void UTimes(const FunctionCallbackInfo<Value>& args) {
} else { // utimes(path, atime, mtime, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(utimes);
SyncCall(env, args[4], &req_wrap_sync, "utime",
uv_fs_utime, *path, atime, mtime);
FS_SYNC_TRACE_END(utimes);
}
}

Expand All @@ -1730,8 +1801,10 @@ static void FUTimes(const FunctionCallbackInfo<Value>& args) {
} else { // futimes(fd, atime, mtime, undefined, ctx)
CHECK_EQ(argc, 5);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(futimes);
SyncCall(env, args[4], &req_wrap_sync, "futime",
uv_fs_futime, fd, atime, mtime);
FS_SYNC_TRACE_END(futimes);
}
}

Expand All @@ -1753,8 +1826,10 @@ static void Mkdtemp(const FunctionCallbackInfo<Value>& args) {
} else { // mkdtemp(tmpl, encoding, undefined, ctx)
CHECK_EQ(argc, 4);
FSReqWrapSync req_wrap_sync;
FS_SYNC_TRACE_BEGIN(mkdtemp);
SyncCall(env, args[3], &req_wrap_sync, "mkdtemp",
uv_fs_mkdtemp, *tmpl);
FS_SYNC_TRACE_END(mkdtemp);
const char* path = static_cast<const char*>(req_wrap_sync.req.path);

Local<Value> error;
Expand Down
6 changes: 6 additions & 0 deletions src/tracing/trace_event_common.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -271,6 +271,9 @@
// does nothing.
// - category and name strings must have application lifetime (statics or
// literals). They may not include " chars.
#define TRACE_EVENT_BEGIN(category_group, name, ...) \
INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, category_group, name, \
TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__)
#define TRACE_EVENT_BEGIN0(category_group, name) \
INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_BEGIN, category_group, name, \
TRACE_EVENT_FLAG_NONE)
Expand Down Expand Up @@ -327,6 +330,9 @@
// is not enabled, then this does nothing.
// - category and name strings must have application lifetime (statics or
// literals). They may not include " chars.
#define TRACE_EVENT_END(category_group, name, ...) \
INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, category_group, name, \
TRACE_EVENT_FLAG_NONE, ##__VA_ARGS__)
#define TRACE_EVENT_END0(category_group, name) \
INTERNAL_TRACE_EVENT_ADD(TRACE_EVENT_PHASE_END, category_group, name, \
TRACE_EVENT_FLAG_NONE)
Expand Down
Loading