trace_events: trace net connect event

Author: theanarkh

doc/api/tracing.md

@@ -23,6 +23,7 @@ The available categories are:
 * `node.console`: Enables capture of `console.time()` and `console.count()`
   output.
 * `node.dns.native`: Enables capture of trace data for DNS queries.
+* `node.net.native`: Enables capture of trace data for network.
 * `node.environment`: Enables capture of Node.js Environment milestones.
 * `node.fs.sync`: Enables capture of trace data for file system sync methods.
 * `node.perf`: Enables capture of [Performance API][] measurements.

src/connection_wrap.cc

@@ -108,6 +108,10 @@ void ConnectionWrap<WrapType, UVType>::AfterConnect(uv_connect_t* req,
     Boolean::New(env->isolate(), writable)
   };
 
+  TRACE_EVENT_NESTABLE_ASYNC_END1(
+    TRACING_CATEGORY_NODE2(net, native),
+    "connect", req_wrap.get(), "status", status);
+
   req_wrap->MakeCallback(env->oncomplete_string(), arraysize(argv), argv);
 }
 

src/pipe_wrap.cc

@@ -241,6 +241,10 @@ void PipeWrap::Connect(const FunctionCallbackInfo<Value>& args) {
                      *name,
                      AfterConnect);
 
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN1(
+    TRACING_CATEGORY_NODE2(net, native), "connect", req_wrap,
+    "pipe_path", TRACE_STR_COPY(*name));
+
   args.GetReturnValue().Set(0);  // uv_pipe_connect() doesn't return errors.
 }
 

src/tcp_wrap.cc

@@ -335,8 +335,18 @@ void TCPWrap::Connect(const FunctionCallbackInfo<Value>& args,
                              &wrap->handle_,
                              reinterpret_cast<const sockaddr*>(&addr),
                              AfterConnect);
-    if (err)
+    if (err) {
       delete req_wrap;
+    } else {
+      int port = args[2]->Uint32Value(env->context()).FromJust();
+      TRACE_EVENT_NESTABLE_ASYNC_BEGIN2(TRACING_CATEGORY_NODE2(net, native),
+                                        "connect",
+                                        req_wrap,
+                                        "ip",
+                                        TRACE_STR_COPY(*ip_address),
+                                        "port",
+                                        port);
+    }
   }
 
   args.GetReturnValue().Set(err);

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

@@ -0,0 +1,53 @@
+'use strict';
+const common = require('../common');
+const assert = require('assert');
+const cp = require('child_process');
+const fs = require('fs');
+const path = require('path');
+const tmpdir = require('../common/tmpdir');
+
+const CODE = `
+  const net = require('net');
+  {
+    const server = net.createServer((socket) => {
+      socket.destroy();
+      server.close();
+    }).listen('${common.PIPE}', () => {
+      net.connect('${common.PIPE}');
+    });
+  }
+  {
+    const server = net.createServer((socket) => {
+      socket.destroy();
+      server.close();
+    }).listen(0, () => {
+      net.connect(server.address().port);
+    });
+  }
+`;
+
+tmpdir.refresh();
+const FILE_NAME = path.join(tmpdir.path, 'node_trace.1.log');
+
+const proc = cp.spawn(process.execPath,
+                      [ '--trace-events-enabled',
+                        '--trace-event-categories', 'node.net.native',
+                        '-e', CODE ],
+                      { cwd: tmpdir.path });
+
+proc.once('exit', common.mustCall(() => {
+  assert(fs.existsSync(FILE_NAME));
+  fs.readFile(FILE_NAME, common.mustCall((err, data) => {
+    const traces = JSON.parse(data.toString()).traceEvents;
+    assert(traces.length > 0);
+    let count = 0;
+    traces.forEach((trace) => {
+      if (trace.cat === 'node,node.net,node.net.native' &&
+          trace.name === 'connect') {
+        count++;
+      }
+    });
+    // Two begin, two end
+    assert.strictEqual(count, 4);
+  }));
+}));