Skip to content

Commit

Permalink
fs: trace more fs api
Browse files Browse the repository at this point in the history
  • Loading branch information
theanarkh committed Oct 20, 2022
1 parent 806ea92 commit 11dcbf1
Show file tree
Hide file tree
Showing 3 changed files with 89 additions and 2 deletions.
2 changes: 2 additions & 0 deletions src/node_dir.cc
Expand Up @@ -135,7 +135,9 @@ void DirHandle::MemoryInfo(MemoryTracker* tracker) const {
inline void DirHandle::GCClose() {
if (closed_) return;
uv_fs_t req;
FS_DIR_SYNC_TRACE_BEGIN(closedir);
int ret = uv_fs_closedir(nullptr, &req, dir_, nullptr);
FS_DIR_SYNC_TRACE_END(closedir);
uv_fs_req_cleanup(&req);
closing_ = false;
closed_ = true;
Expand Down
17 changes: 15 additions & 2 deletions src/node_file.cc
Expand Up @@ -302,7 +302,9 @@ FileHandle::TransferData::~TransferData() {
if (fd_ > 0) {
uv_fs_t close_req;
CHECK_NE(fd_, -1);
FS_SYNC_TRACE_BEGIN(close);
CHECK_EQ(0, uv_fs_close(nullptr, &close_req, fd_, nullptr));
FS_SYNC_TRACE_END(close);
uv_fs_req_cleanup(&close_req);
}
}
Expand All @@ -327,7 +329,9 @@ inline void FileHandle::Close() {
if (closed_ || closing_) return;
uv_fs_t req;
CHECK_NE(fd_, -1);
FS_SYNC_TRACE_BEGIN(close);
int ret = uv_fs_close(env()->event_loop(), &req, fd_, nullptr);
FS_SYNC_TRACE_END(close);
uv_fs_req_cleanup(&req);

struct err_detail { int ret; int fd; };
Expand Down Expand Up @@ -460,7 +464,10 @@ MaybeLocal<Promise> FileHandle::ClosePromise() {

CloseReq* req = new CloseReq(env(), close_req_obj, promise, object());
auto AfterClose = uv_fs_callback_t{[](uv_fs_t* req) {
BaseObjectPtr<CloseReq> close(CloseReq::from_req(req));
CloseReq* req_wrap = CloseReq::from_req(req);
FS_ASYNC_TRACE_END1(
req->fs_type, req_wrap, "result", static_cast<int>(req->result))
BaseObjectPtr<CloseReq> close(req_wrap);
CHECK(close);
close->file_handle()->AfterClose();
if (!close->env()->can_call_into_js()) return;
Expand All @@ -474,6 +481,7 @@ MaybeLocal<Promise> FileHandle::ClosePromise() {
}
}};
CHECK_NE(fd_, -1);
FS_ASYNC_TRACE_BEGIN0(UV_FS_CLOSE, req)
int ret = req->Dispatch(uv_fs_close, fd_, AfterClose);
if (ret < 0) {
req->Reject(UVException(isolate, ret, "close"));
Expand Down Expand Up @@ -569,7 +577,7 @@ int FileHandle::ReadStart() {
read_wrap->buffer_ = EmitAlloc(recommended_read);

current_read_ = std::move(read_wrap);

FS_ASYNC_TRACE_BEGIN0(UV_FS_READ, current_read_.get())
current_read_->Dispatch(uv_fs_read,
fd_,
&current_read_->buffer_,
Expand All @@ -579,6 +587,8 @@ int FileHandle::ReadStart() {
FileHandle* handle;
{
FileHandleReadWrap* req_wrap = FileHandleReadWrap::from_req(req);
FS_ASYNC_TRACE_END1(
req->fs_type, req_wrap, "result", static_cast<int>(req->result))
handle = req_wrap->file_handle_;
CHECK_EQ(handle->current_read_.get(), req_wrap);
}
Expand Down Expand Up @@ -652,9 +662,12 @@ int FileHandle::DoShutdown(ShutdownWrap* req_wrap) {
FileHandleCloseWrap* wrap = static_cast<FileHandleCloseWrap*>(req_wrap);
closing_ = true;
CHECK_NE(fd_, -1);
FS_ASYNC_TRACE_BEGIN0(UV_FS_CLOSE, wrap)
wrap->Dispatch(uv_fs_close, fd_, uv_fs_callback_t{[](uv_fs_t* req) {
FileHandleCloseWrap* wrap = static_cast<FileHandleCloseWrap*>(
FileHandleCloseWrap::from_req(req));
FS_ASYNC_TRACE_END1(
req->fs_type, wrap, "result", static_cast<int>(req->result))
FileHandle* handle = static_cast<FileHandle*>(wrap->stream());
handle->AfterClose();

Expand Down
72 changes: 72 additions & 0 deletions test/parallel/test-trace-events-fs-handle.js
@@ -0,0 +1,72 @@
'use strict';
require('../common');
const assert = require('assert');
const cp = require('child_process');
const fs = require('fs');
const path = require('path');

if (process.env.isChild === '1') {
const { open, opendir } = require('fs/promises');
const trace_events = require('trace_events');
const tracing = trace_events.createTracing({ categories: ['node.fs.async', 'node.fs.sync', 'node.fs_dir.sync'] });
tracing.enable();
(async function test() {
// Call FileHandle::Close(const FunctionCallbackInfo<Value>& args)
{
let filehandle = null;
try {
filehandle = await open(__filename, 'r');
} finally {
await filehandle.close();
}
}
// Call void FileHandle::Close() during gc
{
let filehandle = null;
try {
filehandle = await open(__filename, 'r');
} finally {
filehandle = null;
}
}
// Call void DirHandle::GCClose() during gc
{
let dir = await opendir('.');
dir = null;
}
gc();
})();
return;
}

const tmpdir = require('../common/tmpdir');
tmpdir.refresh();
const traceFile = path.join(tmpdir.path, 'node_trace.1.log');

cp.spawnSync(process.execPath,
['--expose-gc', __filename],
{ cwd: tmpdir.path, encoding: 'utf8', env: { ...process.env, isChild: '1' } });

assert(fs.existsSync(traceFile));
const data = fs.readFileSync(traceFile);
const traces = JSON.parse(data.toString()).traceEvents;
assert(traces.length > 0);

let syncClose = 0;
let asyncClose = 0;
let syncCloseDir = 0;

traces.forEach((trace) => {
if (trace.cat === 'node,node.fs,node.fs.sync' && trace.name === 'fs.sync.close') {
syncClose++;
} else if (trace.cat === 'node,node.fs,node.fs.async' && trace.name === 'close') {
asyncClose++;
} else if (trace.cat === 'node,node.fs_dir,node.fs_dir.sync' && trace.name === 'fs_dir.sync.closedir') {
syncCloseDir++;
}
});

// One begin event, one end event
assert.strictEqual(syncClose, 2);
assert.strictEqual(asyncClose, 2);
assert.strictEqual(syncCloseDir, 2);

0 comments on commit 11dcbf1

Please sign in to comment.