diff --git a/src/cares_wrap.cc b/src/cares_wrap.cc index 9d3d098734470f..7a119d014f5aa9 100644 --- a/src/cares_wrap.cc +++ b/src/cares_wrap.cc @@ -596,9 +596,10 @@ void ChannelWrap::EnsureServers() { class QueryWrap : public AsyncWrap { public: - QueryWrap(ChannelWrap* channel, Local req_wrap_obj) + QueryWrap(ChannelWrap* channel, Local req_wrap_obj, const char* name) : AsyncWrap(channel->env(), req_wrap_obj, AsyncWrap::PROVIDER_QUERYWRAP), - channel_(channel) { + channel_(channel), + trace_name_(name) { // Make sure the channel object stays alive during the query lifetime. req_wrap_obj->Set(env()->context(), env()->channel_string(), @@ -625,6 +626,9 @@ class QueryWrap : public AsyncWrap { int dnsclass, int type) { channel_->EnsureServers(); + TRACE_EVENT_NESTABLE_ASYNC_BEGIN1( + TRACING_CATEGORY_NODE2(dns, native), trace_name_, this, + "name", TRACE_STR_COPY(name)); ares_query(channel_->cares_channel(), name, dnsclass, type, Callback, static_cast(this)); } @@ -721,6 +725,9 @@ class QueryWrap : public AsyncWrap { extra }; const int argc = arraysize(argv) - extra.IsEmpty(); + TRACE_EVENT_NESTABLE_ASYNC_END0( + TRACING_CATEGORY_NODE2(dns, native), trace_name_, this); + MakeCallback(env()->oncomplete_string(), argc, argv); } @@ -730,6 +737,9 @@ class QueryWrap : public AsyncWrap { Context::Scope context_scope(env()->context()); const char* code = ToErrorCodeString(status); Local arg = OneByteString(env()->isolate(), code); + TRACE_EVENT_NESTABLE_ASYNC_END1( + TRACING_CATEGORY_NODE2(dns, native), trace_name_, this, + "error", status); MakeCallback(env()->oncomplete_string(), 1, &arg); } @@ -743,6 +753,9 @@ class QueryWrap : public AsyncWrap { } ChannelWrap* channel_; + + private: + const char* trace_name_; }; @@ -1173,7 +1186,7 @@ int ParseSoaReply(Environment* env, class QueryAnyWrap: public QueryWrap { public: QueryAnyWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveAny") { } int Send(const char* name) override { @@ -1354,7 +1367,7 @@ class QueryAnyWrap: public QueryWrap { class QueryAWrap: public QueryWrap { public: QueryAWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolve4") { } int Send(const char* name) override { @@ -1402,7 +1415,7 @@ class QueryAWrap: public QueryWrap { class QueryAaaaWrap: public QueryWrap { public: QueryAaaaWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolve6") { } int Send(const char* name) override { @@ -1450,7 +1463,7 @@ class QueryAaaaWrap: public QueryWrap { class QueryCnameWrap: public QueryWrap { public: QueryCnameWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveCname") { } int Send(const char* name) override { @@ -1485,7 +1498,7 @@ class QueryCnameWrap: public QueryWrap { class QueryMxWrap: public QueryWrap { public: QueryMxWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveMx") { } int Send(const char* name) override { @@ -1520,7 +1533,7 @@ class QueryMxWrap: public QueryWrap { class QueryNsWrap: public QueryWrap { public: QueryNsWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveNs") { } int Send(const char* name) override { @@ -1555,7 +1568,7 @@ class QueryNsWrap: public QueryWrap { class QueryTxtWrap: public QueryWrap { public: QueryTxtWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveTxt") { } int Send(const char* name) override { @@ -1589,7 +1602,7 @@ class QueryTxtWrap: public QueryWrap { class QuerySrvWrap: public QueryWrap { public: explicit QuerySrvWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveSrv") { } int Send(const char* name) override { @@ -1622,7 +1635,7 @@ class QuerySrvWrap: public QueryWrap { class QueryPtrWrap: public QueryWrap { public: explicit QueryPtrWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolvePtr") { } int Send(const char* name) override { @@ -1657,7 +1670,7 @@ class QueryPtrWrap: public QueryWrap { class QueryNaptrWrap: public QueryWrap { public: explicit QueryNaptrWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveNaptr") { } int Send(const char* name) override { @@ -1691,7 +1704,7 @@ class QueryNaptrWrap: public QueryWrap { class QuerySoaWrap: public QueryWrap { public: QuerySoaWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "resolveSoa") { } int Send(const char* name) override { @@ -1756,7 +1769,7 @@ class QuerySoaWrap: public QueryWrap { class GetHostByAddrWrap: public QueryWrap { public: explicit GetHostByAddrWrap(ChannelWrap* channel, Local req_wrap_obj) - : QueryWrap(channel, req_wrap_obj) { + : QueryWrap(channel, req_wrap_obj, "reverse") { } int Send(const char* name) override { @@ -1773,6 +1786,11 @@ class GetHostByAddrWrap: public QueryWrap { return UV_EINVAL; // So errnoException() reports a proper error. } + TRACE_EVENT_NESTABLE_ASYNC_BEGIN2( + TRACING_CATEGORY_NODE2(dns, native), "reverse", this, + "name", TRACE_STR_COPY(name), + "family", family == AF_INET ? "ipv4" : "ipv6"); + ares_gethostbyaddr(channel_->cares_channel(), address_buffer, length, @@ -1835,8 +1853,10 @@ void AfterGetAddrInfo(uv_getaddrinfo_t* req, int status, struct addrinfo* res) { Null(env->isolate()) }; + uint64_t n = 0; + const bool verbatim = req_wrap->verbatim(); + if (status == 0) { - int n = 0; Local results = Array::New(env->isolate()); auto add = [&] (bool want_ipv4, bool want_ipv6) { @@ -1864,7 +1884,6 @@ void AfterGetAddrInfo(uv_getaddrinfo_t* req, int status, struct addrinfo* res) { } }; - const bool verbatim = req_wrap->verbatim(); add(true, verbatim); if (verbatim == false) add(false, true); @@ -1879,6 +1898,10 @@ void AfterGetAddrInfo(uv_getaddrinfo_t* req, int status, struct addrinfo* res) { uv_freeaddrinfo(res); + TRACE_EVENT_NESTABLE_ASYNC_END2( + TRACING_CATEGORY_NODE2(dns, native), "lookup", req_wrap, + "count", n, "verbatim", verbatim); + // Make the callback into JavaScript req_wrap->MakeCallback(env->oncomplete_string(), arraysize(argv), argv); @@ -1910,6 +1933,11 @@ void AfterGetNameInfo(uv_getnameinfo_t* req, argv[2] = js_service; } + TRACE_EVENT_NESTABLE_ASYNC_END2( + TRACING_CATEGORY_NODE2(dns, native), "lookupService", req_wrap, + "hostname", TRACE_STR_COPY(hostname), + "service", TRACE_STR_COPY(service)); + // Make the callback into JavaScript req_wrap->MakeCallback(env->oncomplete_string(), arraysize(argv), argv); @@ -1986,6 +2014,12 @@ void GetAddrInfo(const FunctionCallbackInfo& args) { hints.ai_socktype = SOCK_STREAM; hints.ai_flags = flags; + TRACE_EVENT_NESTABLE_ASYNC_BEGIN2( + TRACING_CATEGORY_NODE2(dns, native), "lookup", req_wrap, + "hostname", TRACE_STR_COPY(*hostname), + "family", + family == AF_INET ? "ipv4" : family == AF_INET6 ? "ipv6" : "unspec"); + int err = req_wrap->Dispatch(uv_getaddrinfo, AfterGetAddrInfo, *hostname, @@ -2014,6 +2048,10 @@ void GetNameInfo(const FunctionCallbackInfo& args) { GetNameInfoReqWrap* req_wrap = new GetNameInfoReqWrap(env, req_wrap_obj); + TRACE_EVENT_NESTABLE_ASYNC_BEGIN2( + TRACING_CATEGORY_NODE2(dns, native), "lookupService", req_wrap, + "ip", TRACE_STR_COPY(*ip), "port", port); + int err = req_wrap->Dispatch(uv_getnameinfo, AfterGetNameInfo, reinterpret_cast(&addr), @@ -2145,6 +2183,9 @@ void Cancel(const FunctionCallbackInfo& args) { ChannelWrap* channel; ASSIGN_OR_RETURN_UNWRAP(&channel, args.Holder()); + TRACE_EVENT_INSTANT0(TRACING_CATEGORY_NODE2(dns, native), + "cancel", TRACE_EVENT_SCOPE_THREAD); + ares_cancel(channel->cares_channel()); } diff --git a/test/internet/test-trace-events-dns.js b/test/internet/test-trace-events-dns.js new file mode 100644 index 00000000000000..3eb787a2caf70e --- /dev/null +++ b/test/internet/test-trace-events-dns.js @@ -0,0 +1,68 @@ +'use strict'; +const common = require('../common'); +const assert = require('assert'); +const cp = require('child_process'); +const path = require('path'); +const tmpdir = require('../common/tmpdir'); +const fs = require('fs'); +const util = require('util'); + +if (!common.isMainThread) + common.skip('process.chdir is not available in Workers'); + +const traceFile = 'node_trace.1.log'; + +tmpdir.refresh(); +process.chdir(tmpdir.path); + +const test_str = 'const dns = require("dns");' + +'const options = {' + +' family: 4,' + +' hints: dns.ADDRCONFIG | dns.V4MAPPED,' + +'};'; + +const tests = { + 'lookup': 'dns.lookup("example.com", options, (err, address, family) => {});', + 'lookupService': 'dns.lookupService("127.0.0.1", 22, ' + + '(err, hostname, service) => {});', + 'reverse': 'dns.reverse("8.8.8.8", (err, hostnames) => {});', + 'resolveAny': 'dns.resolveAny("example.com", (err, res) => {});', + 'resolve4': 'dns.resolve4("example.com", (err, res) => {});', + 'resolve6': 'dns.resolve6("example.com", (err, res) => {});', + 'resolveCname': 'dns.resolveCname("example.com", (err, res) => {});', + 'resolveMx': 'dns.resolveMx("example.com", (err, res) => {});', + 'resolveNs': 'dns.resolveNs("example.com", (err, res) => {});', + 'resolveTxt': 'dns.resolveTxt("example.com", (err, res) => {});', + 'resolveSrv': 'dns.resolveSrv("example.com", (err, res) => {});', + 'resolvePtr': 'dns.resolvePtr("example.com", (err, res) => {});', + 'resolveNaptr': 'dns.resolveNaptr("example.com", (err, res) => {});', + 'resolveSoa': 'dns.resolveSoa("example.com", (err, res) => {});' +}; + +for (const tr in tests) { + const proc = cp.spawnSync(process.execPath, + [ '--trace-event-categories', + 'node.dns.native', + '-e', + test_str + tests[tr] + ], + { encoding: 'utf8' }); + + // Make sure the operation is successful. + assert.strictEqual(proc.status, 0, `${tr}:\n${util.inspect(proc)}`); + + const file = path.join(tmpdir.path, traceFile); + + // Confirm that trace log file is created. + assert(common.fileExists(file)); + const data = fs.readFileSync(file); + const traces = JSON.parse(data.toString()).traceEvents + .filter((trace) => trace.cat !== '__metadata'); + + assert(traces.length > 0); + + // DNS native trace events should be generated. + assert(traces.some((trace) => { + return (trace.name === tr && trace.pid === proc.pid); + })); +}