FazBrowse GitHub Viewer | Trending |
URL:
| Home
Tools: [Download Repo ZIP]   [Original HTTPS Page]

net,dns: trace tcp connection and dns by perf_hooks · nodejs/node@b71a810 · GitHub

/ node Public

Commit b71a810

Browse files
theanarkh
authored and
juanarbol
committed
net,dns: trace tcp connection and dns by perf_hooks
use the perf_hooks to trace the time spent by net.connect, dns.lookup, dns.lookupService, dns.resolvexxx. PR-URL: #42390 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Paolo Insogna <paolo@cowtech.it> Reviewed-By: Mohammed Keyvanzadeh <mohammadkeyvanzade94@gmail.com>
1 parent 902776e commit b71a810

8 files changed

Lines changed: 272 additions & 3 deletions

File tree

‎doc/api/perf_hooks.md‎

Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -531,6 +531,30 @@ When `performanceEntry.type` is equal to `'function'`, the
531531
`performanceEntry.detail` property will be an {Array} listing
532532
the input arguments to the timed function.
533533

534+
### Net ('net') Details
535+
536+
When `performanceEntry.type` is equal to `'net'`, the
537+
`performanceEntry.detail` property will be an {Object} containing
538+
additional information.
539+
540+
If `performanceEntry.name` is equal to `connect`, the `detail`
541+
will contain the following properties: `host`, `port`.
542+
543+
### DNS ('dns') Details
544+
545+
When `performanceEntry.type` is equal to `'dns'`, the
546+
`performanceEntry.detail` property will be an {Object} containing
547+
additional information.
548+
549+
If `performanceEntry.name` is equal to `lookup`, the `detail`
550+
will contain the following properties: `hostname`, `family`, `hints`, `verbatim`.
551+
552+
If `performanceEntry.name` is equal to `lookupService`, the `detail` will
553+
contain the following properties: `host`, `port`.
554+
555+
If `performanceEntry.name` is equal to `queryxxx` or `getHostByAddr`, the `detail` will
556+
contain the following properties: `host`, `ttl`.
557+
534558
## Class: `PerformanceNodeTiming`
535559

536560
<!-- YAML
@@ -1284,6 +1308,42 @@ http.createServer((req, res) => {
12841308
});
12851309
```
12861310

1311+
### Measuring how long the `net.connect` (only for TCP) takes when the connection is successful
1312+
1313+
```js
1314+
'use strict';
1315+
const { PerformanceObserver } = require('perf_hooks');
1316+
const net = require('net');
1317+
const obs = new PerformanceObserver((items) => {
1318+
items.getEntries().forEach((item) => {
1319+
console.log(item);
1320+
});
1321+
});
1322+
obs.observe({ entryTypes: ['net'] });
1323+
const PORT = 8080;
1324+
net.createServer((socket) => {
1325+
socket.destroy();
1326+
}).listen(PORT, () => {
1327+
net.connect(PORT);
1328+
});
1329+
```
1330+
1331+
### Measuring how long the DNS takes when the request is successful
1332+
1333+
```js
1334+
'use strict';
1335+
const { PerformanceObserver } = require('perf_hooks');
1336+
const dns = require('dns');
1337+
const obs = new PerformanceObserver((items) => {
1338+
items.getEntries().forEach((item) => {
1339+
console.log(item);
1340+
});
1341+
});
1342+
obs.observe({ entryTypes: ['dns'] });
1343+
dns.lookup('localhost', () => {});
1344+
dns.promises.resolve('localhost');
1345+
```
1346+
12871347
[Async Hooks]: async_hooks.md
12881348
[High Resolution Time]: https://www.w3.org/TR/hr-time-2
12891349
[Performance Timeline]: https://w3c.github.io/performance-timeline/

‎lib/dns.js‎

Lines changed: 39 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@ const {
2727
ObjectDefineProperties,
2828
ObjectDefineProperty,
2929
ReflectApply,
30+
Symbol,
3031
} = primordials;
3132

3233
const cares = internalBinding('cares_wrap');
@@ -63,6 +64,15 @@ const {
6364
QueryReqWrap,
6465
} = cares;
6566

67+
const kPerfHooksDnsLookupContext = Symbol('kPerfHooksDnsLookupContext');
68+
const kPerfHooksDnsLookupServiceContext = Symbol('kPerfHooksDnsLookupServiceContext');
69+
const kPerfHooksDnsLookupResolveContext = Symbol('kPerfHooksDnsLookupResolveContext');
70+
71+
const {
72+
startPerf,
73+
stopPerf,
74+
} = require('internal/perf/observe');
75+
6676
const dnsException = errors.dnsException;
6777

6878
let promises = null; // Lazy loaded
@@ -72,6 +82,7 @@ function onlookup(err, addresses) {
7282
return this.callback(dnsException(err, 'getaddrinfo', this.hostname));
7383
}
7484
this.callback(null, addresses[0], this.family || isIP(addresses[0]));
85+
stopPerf(this, kPerfHooksDnsLookupContext);
7586
}
7687

7788

@@ -90,6 +101,7 @@ function onlookupall(err, addresses) {
90101
}
91102

92103
this.callback(null, addresses);
104+
stopPerf(this, kPerfHooksDnsLookupContext);
93105
}
94106

95107

@@ -176,6 +188,13 @@ function lookup(hostname, options, callback) {
176188
process.nextTick(callback, dnsException(err, 'getaddrinfo', hostname));
177189
return {};
178190
}
191+
const detail = {
192+
hostname,
193+
family,
194+
hints,
195+
verbatim,
196+
};
197+
startPerf(req, kPerfHooksDnsLookupContext, { type: 'dns', name: 'lookup', detail });
179198
return req;
180199
}
181200

@@ -188,6 +207,7 @@ function onlookupservice(err, hostname, service) {
188207
return this.callback(dnsException(err, 'getnameinfo', this.hostname));
189208

190209
this.callback(null, hostname, service);
210+
stopPerf(this, kPerfHooksDnsLookupServiceContext);
191211
}
192212

193213

@@ -212,6 +232,14 @@ function lookupService(address, port, callback) {
212232

213233
const err = cares.getnameinfo(req, address, port);
214234
if (err) throw dnsException(err, 'getnameinfo', address);
235+
startPerf(req, kPerfHooksDnsLookupServiceContext, {
236+
type: 'dns',
237+
name: 'lookupService',
238+
detail: {
239+
host: address,
240+
port
241+
}
242+
});
215243
return req;
216244
}
217245

@@ -226,8 +254,10 @@ function onresolve(err, result, ttls) {
226254

227255
if (err)
228256
this.callback(dnsException(err, this.bindingName, this.hostname));
229-
else
257+
else {
230258
this.callback(null, result);
259+
stopPerf(this, kPerfHooksDnsLookupResolveContext);
260+
}
231261
}
232262

233263
function resolver(bindingName) {
@@ -249,6 +279,14 @@ function resolver(bindingName) {
249279
req.ttl = !!(options && options.ttl);
250280
const err = this._handle[bindingName](req, toASCII(name));
251281
if (err) throw dnsException(err, bindingName, name);
282+
startPerf(req, kPerfHooksDnsLookupResolveContext, {
283+
type: 'dns',
284+
name: bindingName,
285+
detail: {
286+
host: name,
287+
ttl: req.ttl
288+
}
289+
});
252290
return req;
253291
}
254292
ObjectDefineProperty(query, 'name', { value: bindingName });

‎lib/internal/dns/promises.js‎

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ const {
55
ObjectDefineProperty,
66
Promise,
77
ReflectApply,
8+
Symbol,
89
} = primordials;
910

1011
const {
@@ -38,6 +39,15 @@ const {
3839
validateOneOf,
3940
} = require('internal/validators');
4041

42+
const kPerfHooksDnsLookupContext = Symbol('kPerfHooksDnsLookupContext');
43+
const kPerfHooksDnsLookupServiceContext = Symbol('kPerfHooksDnsLookupServiceContext');
44+
const kPerfHooksDnsLookupResolveContext = Symbol('kPerfHooksDnsLookupResolveContext');
45+
46+
const {
47+
startPerf,
48+
stopPerf,
49+
} = require('internal/perf/observe');
50+
4151
function onlookup(err, addresses) {
4252
if (err) {
4353
this.reject(dnsException(err, 'getaddrinfo', this.hostname));
@@ -46,6 +56,7 @@ function onlookup(err, addresses) {
4656

4757
const family = this.family || isIP(addresses[0]);
4858
this.resolve({ address: addresses[0], family });
59+
stopPerf(this, kPerfHooksDnsLookupContext);
4960
}
5061

5162
function onlookupall(err, addresses) {
@@ -66,6 +77,7 @@ function onlookupall(err, addresses) {
6677
}
6778

6879
this.resolve(addresses);
80+
stopPerf(this, kPerfHooksDnsLookupContext);
6981
}
7082

7183
function createLookupPromise(family, hostname, all, hints, verbatim) {
@@ -96,6 +108,14 @@ function createLookupPromise(family, hostname, all, hints, verbatim) {
96108

97109
if (err) {
98110
reject(dnsException(err, 'getaddrinfo', hostname));
111+
} else {
112+
const detail = {
113+
hostname,
114+
family,
115+
hints,
116+
verbatim,
117+
};
118+
startPerf(req, kPerfHooksDnsLookupContext, { type: 'dns', name: 'lookup', detail });
99119
}
100120
});
101121
}
@@ -151,6 +171,7 @@ function onlookupservice(err, hostname, service) {
151171
}
152172

153173
this.resolve({ hostname, service });
174+
stopPerf(this, kPerfHooksDnsLookupServiceContext);
154175
}
155176

156177
function createLookupServicePromise(hostname, port) {
@@ -167,6 +188,15 @@ function createLookupServicePromise(hostname, port) {
167188

168189
if (err)
169190
reject(dnsException(err, 'getnameinfo', hostname));
191+
else
192+
startPerf(req, kPerfHooksDnsLookupServiceContext, {
193+
type: 'dns',
194+
name: 'lookupService',
195+
detail: {
196+
host: hostname,
197+
port
198+
}
199+
});
170200
});
171201
}
172202

@@ -194,6 +224,7 @@ function onresolve(err, result, ttls) {
194224
result, (address, index) => ({ address, ttl: ttls[index] }));
195225

196226
this.resolve(result);
227+
stopPerf(this, kPerfHooksDnsLookupResolveContext);
197228
}
198229

199230
function createResolverPromise(resolver, bindingName, hostname, ttl) {
@@ -211,6 +242,16 @@ function createResolverPromise(resolver, bindingName, hostname, ttl) {
211242

212243
if (err)
213244
reject(dnsException(err, bindingName, hostname));
245+
else {
246+
startPerf(req, kPerfHooksDnsLookupResolveContext, {
247+
type: 'dns',
248+
name: bindingName,
249+
detail: {
250+
host: hostname,
251+
ttl
252+
}
253+
});
254+
}
214255
});
215256
}
216257

‎lib/internal/perf/observe.js‎

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,8 @@ const {
2424
NODE_PERFORMANCE_ENTRY_TYPE_GC,
2525
NODE_PERFORMANCE_ENTRY_TYPE_HTTP2,
2626
NODE_PERFORMANCE_ENTRY_TYPE_HTTP,
27+
NODE_PERFORMANCE_ENTRY_TYPE_NET,
28+
NODE_PERFORMANCE_ENTRY_TYPE_DNS,
2729
},
2830
installGarbageCollectionTracking,
2931
observerCounts,
@@ -79,12 +81,14 @@ const kTypeMultiple = 1;
7981
let gcTrackingInstalled = false;
8082

8183
const kSupportedEntryTypes = ObjectFreeze([
84+
'dns',
8285
'function',
8386
'gc',
8487
'http',
8588
'http2',
8689
'mark',
8790
'measure',
91+
'net',
8892
]);
8993

9094
// Performance timeline entry Buffers
@@ -118,6 +122,8 @@ function getObserverType(type) {
118122
case 'gc': return NODE_PERFORMANCE_ENTRY_TYPE_GC;
119123
case 'http2': return NODE_PERFORMANCE_ENTRY_TYPE_HTTP2;
120124
case 'http': return NODE_PERFORMANCE_ENTRY_TYPE_HTTP;
125+
case 'net': return NODE_PERFORMANCE_ENTRY_TYPE_NET;
126+
case 'dns': return NODE_PERFORMANCE_ENTRY_TYPE_DNS;
121127
}
122128
}
123129

@@ -443,11 +449,39 @@ function hasObserver(type) {
443449
return observerCounts[observerType] > 0;
444450
}
445451

452+
453+
function startPerf(target, key, context = {}) {
454+
if (hasObserver(context.type)) {
455+
target[key] = {
456+
...context,
457+
startTime: process.hrtime(),
458+
};
459+
}
460+
}
461+
462+
function stopPerf(target, key, context = {}) {
463+
const ctx = target[key];
464+
if (ctx && hasObserver(ctx.type)) {
465+
const startTime = ctx.startTime;
466+
const diff = process.hrtime(startTime);
467+
const entry = new InternalPerformanceEntry(
468+
ctx.name,
469+
ctx.type,
470+
startTime[0] * 1000 + startTime[1] / 1e6,
471+
diff[0] * 1000 + diff[1] / 1e6,
472+
{ ...ctx.detail, ...context.detail },
473+
);
474+
enqueue(entry);
475+
}
476+
}
477+
446478
module.exports = {
447479
PerformanceObserver,
448480
PerformanceObserverEntryList,
449481
enqueue,
450482
hasObserver,
451483
clearEntriesFromBuffer,
452484
filterBufferMapByNameAndType,
485+
startPerf,
486+
stopPerf,
453487
};

‎lib/net.js‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -130,6 +130,12 @@ const isWindows = process.platform === 'win32';
130130

131131
const noop = () => {};
132132

133+
const kPerfHooksNetConnectContext = Symbol('kPerfHooksNetConnectContext');
134+
const {
135+
startPerf,
136+
stopPerf,
137+
} = require('internal/perf/observe');
138+
133139
function getFlags(ipv6Only) {
134140
return ipv6Only === true ? TCPConstants.UV_TCP_IPV6ONLY : 0;
135141
}
@@ -952,6 +958,8 @@ function internalConnect(
952958

953959
const ex = exceptionWithHostPort(err, 'connect', address, port, details);
954960
self.destroy(ex);
961+
} else if (addressType === 6 || addressType === 4) {
962+
startPerf(self, kPerfHooksNetConnectContext, { type: 'net', name: 'connect', detail: { host: address, port } });
955963
}
956964
}
957965

@@ -1177,7 +1185,7 @@ function afterConnect(status, handle, req, readable, writable) {
11771185
// this doesn't actually consume any bytes, because len=0.
11781186
if (readable && !self.isPaused())
11791187
self.read(0);
1180-
1188+
stopPerf(self, kPerfHooksNetConnectContext);
11811189
} else {
11821190
self.connecting = false;
11831191
let details;

‎src/node_perf_common.h‎

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,9 @@ extern uint64_t performance_v8_start;
3434
#define NODE_PERFORMANCE_ENTRY_TYPES(V) \
3535
V(GC, "gc") \
3636
V(HTTP, "http") \
37-
V(HTTP2, "http2")
37+
V(HTTP2, "http2") \
38+
V(NET, "net") \
39+
V(DNS, "dns")
3840

3941
enum PerformanceMilestone {
4042
#define V(name, _) NODE_PERFORMANCE_MILESTONE_##name,

0 commit comments

Comments
 (0)
Back | FazBrowse Home | New Git URL