src: add trace points to dns #21840

chinhuang007 · 2018-07-16T20:37:54Z

Add trace points to dns under node.dns category.
Emit trace events for dns operations. Use the
nestable async events instead of deprecated ones.
Include test code to verify the trace log.

Refs: #19157

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
[x ] tests and/or benchmarks are included
[x ] commit message follows commit guidelines

addaleax · 2018-07-16T21:03:04Z

src/cares_wrap.cc

@@ -714,6 +719,9 @@ class QueryWrap : public AsyncWrap {
      extra
    };
    const int argc = arraysize(argv) - extra.IsEmpty();
+    static const std::string trace_name = name_;
+    TRACE_EVENT_NESTABLE_ASYNC_END0("node,node.dns", trace_name.c_str(), this);


This looks odd … this means that trace_name is initialized once and not changed afterwards? What if this function gets called with instances of QueryWrap that have different names?

I think things might end up being easier if you store the original const char* itself on the class and always pass that to the trace macros. That might require the string to be given at compile time, but I’d think that’s okay.

Thanks for pointing it out. I will need to fix it.

gireeshpunathil · 2018-07-17T04:11:41Z

src/cares_wrap.cc

      : AsyncWrap(channel->env(), req_wrap_obj, AsyncWrap::PROVIDER_QUERYWRAP),
-        channel_(channel) {
+        channel_(channel),
+        trace_name_(name) {


does this change cause any external JS API interface change? I guess not.

No, this is all internal.

gireeshpunathil · 2018-07-17T04:12:24Z

test/parallel/test-trace-events-dns.js

+'dns.resolveSrv("example.com", (err, res) => {});' +
+'dns.resolvePtr("example.com", (err, res) => {});' +
+'dns.resolveNaptr("example.com", (err, res) => {});' +
+'dns.resolveSoa("example.com", (err, res) => {});';


does it make sense to wrap all these callbacks into common.mustCall semantic?

Thanks for the comments. The callbacks are not significant in the trace log test case. There are existing test files that cover general dns features. The main focus here is to ensure an expected trace log is written to the trace output file. I did break the all-in-one test into individual tests so it will be easier to pinpoint the problem should an error occurs.

makes sense, thanks. My experience showed that issues are often caught by test cases that were not designed to test such issues. Moreover the semantic which we are talking about is present in every piece of test code that has a completion handler callback. But definitely not a reason for tests to overload cases, and I am fine here.

jasnell · 2018-07-17T05:18:21Z

src/cares_wrap.cc

@@ -618,6 +620,9 @@ class QueryWrap : public AsyncWrap {
                 int dnsclass,
                 int type) {
    channel_->EnsureServers();
+    TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(
+      "node,node.dns", trace_name_, this,


Let's make the category on these node.dns.native. Once we have the V8 trace instrinsic landed they will be paired up with the node.dns.js side.

Also, there's a macro to make the naming easier... e.g. TRACING_CATEGORY_NODE2(dns, native) expands to node,node.dns,node.dns.native to ensure we have a proper hierarchy.

Thanks for the comments. I changed the category to node.dns.native, also started to use TRACING_CATEGORY_NODE2(dns, native).

addaleax · 2018-07-17T07:12:44Z

src/cares_wrap.cc

      : AsyncWrap(channel->env(), req_wrap_obj, AsyncWrap::PROVIDER_QUERYWRAP),
-        channel_(channel) {
+        channel_(channel),
+        trace_name_(name) {


No, this is all internal.

addaleax · 2018-07-17T07:13:44Z

test/parallel/test-trace-events-dns.js

@@ -0,0 +1,86 @@
+'use strict';


This test should probably go into test/internet?

Honestly I are not sure the technical differences between test/internet and test/parallel. I saw dns test code in both folders. For now, I put this under test/parallel, along with other test-trace-events-xxx test files. I don't mind to move if it should go to test/internet by definition.

@chinhuang007 Generally, test that reach out to random internet servers should go into test/internet – think of it as tests that could be affected by e.g. a firewall. These tests aren’t run as part of a standard make test, though.

There are DNS tests in test/parallel, but (I think) most of those use a DNS mock implementation (e.g. test/parallel/test-dns-resolveany.js) – that’s nice, because it means that the test is fully self-contained and doesn’t do any networking outside the local host, but it also comes with some overhead when writing the test.

It’s a tradeoff, and you can choose to go either route, but if you keep the test as it is, please move it. :)

Okay, moved the test code to test/parallel. Thanks for your explanation!

chinhuang007 · 2018-07-23T23:33:54Z

What's the next step to move it forward?

chinhuang007 · 2018-07-25T17:08:33Z

If no changes are needed, can someone help start the merge/land process?

addaleax · 2018-07-25T17:13:22Z

@chinhuang007 I think this is technically ready, but /cc @joyeecheung because https://github.com/nodejs/node/pull/21939/files#diff-5a543a2c1d958ec924db11553ecfb703 also adds string identifiers to all of the different query classes

CI: https://ci.nodejs.org/job/node-test-pull-request/16004/

joyeecheung · 2018-07-26T02:20:43Z

src/cares_wrap.cc

+      TRACING_CATEGORY_NODE2(dns, native), "lookup", req_wrap,
+      "hostname", TRACE_STR_COPY(*hostname),
+      "family",
+      family == AF_INET ? "ip4" : family == AF_INET6 ? "ip6" : "unspec");


Is there a reason these are ip4 and ip6 instead of ipv4 and ipv6? (like the ones in GetHostByAddrWrap)

Thanks for catching it. Just fixed it.

joyeecheung · 2018-07-26T02:23:32Z

It should be orthogonal to #21939 since the naming here is for time spent on (JS-API-ish) operations (measured in microseconds) instead of internal types of chunks in memory (measured in bytes).

chinhuang007 · 2018-07-27T00:28:23Z

Thanks, @joyeecheung for the review and comments. I fixed a CI problem for osx. Can someone help start a new CI?

gireeshpunathil · 2018-07-27T01:11:15Z

CI: https://ci.nodejs.org/job/node-test-pull-request/16020/

chinhuang007 · 2018-08-01T21:15:44Z

The CI build problem doesn't seem related this PR. Can someone start a new CI to see if the problem is repeatable?

yhwang · 2018-08-01T22:33:47Z

New CI: https://ci.nodejs.org/job/node-test-commit/20136/

chinhuang007 · 2018-08-06T17:28:35Z

Please let me know if anything else needs to be done before this PR can be merged/landed. Thanks!

jasnell · 2018-08-12T20:45:43Z

CI: https://ci.nodejs.org/job/node-test-pull-request/16396/

yhwang · 2018-08-16T18:17:00Z

new CI: https://ci.nodejs.org/job/node-test-pull-request/16491/

chinhuang007 · 2018-08-17T18:06:16Z

@jasnell Thanks for starting the CI. Somehow some tests failed on unrelated build issues. I wonder if you can help merge/land it?

jasnell · 2018-08-18T04:02:44Z

New CI: https://ci.nodejs.org/job/node-test-pull-request/16525/

addaleax · 2018-08-18T16:46:13Z

Once again, CI: https://ci.nodejs.org/job/node-test-pull-request/16544/

joyeecheung · 2018-08-20T01:16:28Z

This PR needs a rebase against master to avoid the git failure in the CI.

Add trace points to dns under node.dns.native category. Emit trace events for dns operations. Use the nestable async events instead of deprecated ones. Include test code to verify the trace log. The trace name is stored as const char* class variable. The test code is to check each operation in separate sync processes. Refs: nodejs#19157

chinhuang007 · 2018-08-20T18:19:50Z

Thanks for the CIs and comments. I just rebased and locally tested. Hope the next CI will be clean.

joyeecheung · 2018-08-20T19:26:22Z

CI: https://ci.nodejs.org/job/node-test-pull-request/16615/

addaleax · 2018-08-20T21:39:06Z

Only one unrelated FreeBSD failure remaining 😄

Resume build: https://ci.nodejs.org/job/node-test-pull-request/16619/

chinhuang007 · 2018-09-02T19:04:25Z

Just rebased and passed tests. Do we need to start a new CI, hoping no unrelated errors? Please advice what I can do to help land it.

addaleax · 2018-09-02T19:36:16Z

@chinhuang007 Sorry, all that was needed was a ping to remind us – landed in b366de5!

Add trace points to dns under node.dns.native category. Emit trace events for dns operations. Use the nestable async events instead of deprecated ones. Include test code to verify the trace log. The trace name is stored as const char* class variable. The test code is to check each operation in separate sync processes. Refs: #19157 PR-URL: #21840 Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

refack · 2018-09-03T15:47:41Z

Since this test is in /internet/ it is not covered by our regular CI.
Daily run picked up https://ci.nodejs.org/job/node-test-commit-custom-suites/675/default/testReport/junit/(root)/test/internet_test_trace_events_dns/

Update: Fix PR #22674

Add trace points to dns under node.dns.native category. Emit trace events for dns operations. Use the nestable async events instead of deprecated ones. Include test code to verify the trace log. The trace name is stored as const char* class variable. The test code is to check each operation in separate sync processes. Refs: #19157 PR-URL: #21840 Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

As implemented in nodejs#21840, dns can emit trace events when the category is enabled. This PR just add it to the documentation.

As implemented in nodejs#21840, dns can emit trace events when the category is enabled. This PR just add it to the documentation. PR-URL: nodejs#28100 Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

As implemented in #21840, dns can emit trace events when the category is enabled. This PR just add it to the documentation. PR-URL: #28100 Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Rich Trott <rtrott@gmail.com> Reviewed-By: James M Snell <jasnell@gmail.com>

nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. cares Issues and PRs related to the c-ares dependency or the cares_wrap binding. labels Jul 16, 2018

addaleax reviewed Jul 16, 2018

View reviewed changes

addaleax added the trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events. label Jul 16, 2018

chinhuang007 force-pushed the add_dns_trace branch from b16b527 to 1c15db6 Compare July 16, 2018 23:19

gireeshpunathil reviewed Jul 17, 2018

View reviewed changes

jasnell reviewed Jul 17, 2018

View reviewed changes

addaleax approved these changes Jul 17, 2018

View reviewed changes

chinhuang007 force-pushed the add_dns_trace branch 2 times, most recently from 33668dd to d7ede7a Compare July 18, 2018 00:17

jasnell approved these changes Jul 18, 2018

View reviewed changes

gireeshpunathil approved these changes Jul 18, 2018

View reviewed changes

cjihrig approved these changes Jul 19, 2018

View reviewed changes

chinhuang007 force-pushed the add_dns_trace branch 2 times, most recently from 849f83b to 128e866 Compare July 26, 2018 00:28

joyeecheung reviewed Jul 26, 2018

View reviewed changes

chinhuang007 force-pushed the add_dns_trace branch 3 times, most recently from 7d401e2 to 420daf0 Compare July 27, 2018 00:04

joyeecheung approved these changes Jul 27, 2018

View reviewed changes

joyeecheung mentioned this pull request Aug 17, 2018

CI Failures: 20180817 nodejs/reliability#14

Closed

joyeecheung mentioned this pull request Aug 20, 2018

CI failures: 20180820 nodejs/reliability#15

Closed

chinhuang007 force-pushed the add_dns_trace branch from 60cf701 to 7ceedb9 Compare August 20, 2018 16:10

addaleax closed this Sep 2, 2018

refack mentioned this pull request Sep 3, 2018

test: remove common.fileExists() #22151

Closed

3 tasks

targos mentioned this pull request Sep 5, 2018

Release proposal: v10.10.0 #22716

Merged

This was referenced Sep 6, 2018

2018-09-06 Version 10.10.0 (Current) @targos beevelop/docker-android-nodejs#236

Closed

2018-09-06 Version 10.10.0 (Current) @targos beevelop/docker-nodejs#221

Closed

vmarchaud mentioned this pull request Jun 6, 2019

doc: document trace-events category for dns requests #28100

Closed

4 tasks

vmarchaud added a commit to vmarchaud/node that referenced this pull request Jun 7, 2019

doc: document trace-events category for dns requests

bfeb47e

As implemented in nodejs#21840, dns can emit trace events when the category is enabled. This PR just add it to the documentation.

src: add trace points to dns #21840

src: add trace points to dns #21840

Conversation

chinhuang007 commented Jul 16, 2018

Checklist

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

chinhuang007 commented Jul 23, 2018

chinhuang007 commented Jul 25, 2018

addaleax commented Jul 25, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

joyeecheung commented Jul 26, 2018

chinhuang007 commented Jul 27, 2018

gireeshpunathil commented Jul 27, 2018

chinhuang007 commented Aug 1, 2018

yhwang commented Aug 1, 2018

chinhuang007 commented Aug 6, 2018

jasnell commented Aug 12, 2018

yhwang commented Aug 16, 2018

chinhuang007 commented Aug 17, 2018

jasnell commented Aug 18, 2018

addaleax commented Aug 18, 2018

joyeecheung commented Aug 20, 2018

chinhuang007 commented Aug 20, 2018

joyeecheung commented Aug 20, 2018

addaleax commented Aug 20, 2018

chinhuang007 commented Sep 2, 2018

addaleax commented Sep 2, 2018

refack commented Sep 3, 2018 • edited

refack commented Sep 3, 2018 •

edited