Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perf_hooks: add HttpRequest statistics monitoring #28445 #28486

Closed
wants to merge 1 commit into from

Conversation

vmarchaud
Copy link
Contributor

Add a way to track http request timing directly via perf_hooks:

const { PerformanceObserver, performance } = require('perf_hooks');
const http = require('http');

const obs = new PerformanceObserver((items) => {
  const entry = items.getEntries()[0];
  console.log(entry.name, entry.duration);
});
obs.observe({ entryTypes: ['http'] });

const server = http.Server(function(req, res) {
  server.close();
  res.writeHead(200);
  res.end('hello world\n');
});

server.listen(0, function() {
  const req = http.request({
    port: this.address().port,
    path: '/',
    method: 'POST'
  }).end();
});

I initially started this by adding inside the socket state but it could lead to race condition where multiple request on the same socket would mess with each other timings.
The downside of this approach is that we can't track how much it take to parse the header or how much byte we read/write for this connection, it would require to add more hook to the ServerResponse that could impact performance.
Since generally we want to monitor how much times it take by userland to process the request, since approach should be enough.

I've also added a generic Notify on the performance c++ to allow any core js-land module to broadcast PerformanceEntry, it should allow to instrument other core js module. There still a problem through, this method will not broadcast trace_events for each perf entry, i don't know if it really necessary ?

cc @jasnell

Checklist
  • make -j4 test (UNIX), or vcbuild test (Windows) passes
  • tests and/or benchmarks are included
  • documentation is changed or added
  • commit message follows commit guidelines

@nodejs-github-bot nodejs-github-bot added c++ Issues and PRs that require attention from people who are familiar with C++. lib / src Issues and PRs related to general changes in the lib or src directory. labels Jun 30, 2019
@mscdex
Copy link
Contributor

mscdex commented Jun 30, 2019

Can't we add some conditionals to avoid these extra bits of code at runtime?

@vmarchaud
Copy link
Contributor Author

@mscdex I believe we could check when we call emitStatistics (which will avoid instanciating the PerformanceEntry class and calling the C++ side), but i'm not sure if it's really worth to add a if for the stats object itself.
Since the observers of perf_hooks can be created at runtime (and there are handled on the c++ side), adding a if would mean calling C++ for every request anyway.

test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
test/parallel/test-http-perf_hooks.js Outdated Show resolved Hide resolved
lib/_http_server.js Outdated Show resolved Hide resolved
lib/internal/http.js Outdated Show resolved Hide resolved
src/node_perf.cc Outdated Show resolved Hide resolved
@addaleax addaleax added http Issues or PRs related to the http subsystem. perf_hooks Issues and PRs related to the implementation of the Performance Timing API. and removed lib / src Issues and PRs related to general changes in the lib or src directory. labels Jul 1, 2019
@mscdex
Copy link
Contributor

mscdex commented Jul 1, 2019

Since the observers of perf_hooks can be created at runtime (and there are handled on the c++ side), adding a if would mean calling C++ for every request anyway.

Not necessarily. Modules could register hooks that get called from C++ whenever a particular "observer" is enabled/disabled. These hooks could then simply set a local (to the module) boolean variable that is checked in the actual code.

EDIT: After briefly reviewing perf_hooks.js and related C++ code, it seems if JavaScript is the only place where performance hooks can be enabled/disabled, then we shouldn't even need to go through C++ at all, we could either just call these per-module hooks directly, have a lookup table of enabled/disabled status for each module, or have a way for each module to (if I'm understanding perf_hooks.js correctly) check observerCounts.http > 0 for example.

@vmarchaud
Copy link
Contributor Author

@mscdex I'm not really aware of how the frontier works but the observers table is on the c++ side here, the only thing exposed to JS land is the observersCount, which we could use to check that indeed but i counted it as a C++ call.
If that's it, i would add a check before emitting the stats. Do you think it's worth to check the table when creating the this[kServerResponseStatistics] object too ?

@addaleax
Copy link
Member

addaleax commented Jul 1, 2019

@vmarchaud Accessing typed arrays created in C++, like observersCount, is essentially free and doesn’t call into C++.

@vmarchaud
Copy link
Contributor Author

Done. I hardcoded the index of the http entry in the observersCount since it's quite difficult to access it (it's only declared in perf_hooks and on the C++ side), i'm not sure if it's the right way though

src/node_perf.cc Outdated Show resolved Hide resolved
src/node_perf.cc Outdated Show resolved Hide resolved
@vmarchaud vmarchaud force-pushed the http-perf-hooks branch 2 times, most recently from b0df4ba to d8a7384 Compare July 2, 2019 14:18
src/node_perf.cc Outdated Show resolved Hide resolved
lib/_http_server.js Outdated Show resolved Hide resolved
lib/_http_server.js Outdated Show resolved Hide resolved
@addaleax addaleax added the author ready PRs that have at least one approval, no pending requests for changes, and a CI started. label Jul 6, 2019
@nodejs-github-bot
Copy link
Collaborator

lib/internal/http.js Outdated Show resolved Hide resolved
lib/internal/http.js Outdated Show resolved Hide resolved
```js
const { PerformanceObserver, performance } = require('perf_hooks');
const http = require('http');

const obs = new PerformanceObserver((items) => {
  const entry = items.getEntries()[0];
  console.log(entry.name, entry.duration);
});
obs.observe({ entryTypes: ['http'] });

const server = http.Server(function(req, res) {
  server.close();
  res.writeHead(200);
  res.end('hello world\n');
});

server.listen(0, function() {
  const req = http.request({
    port: this.address().port,
    path: '/',
    method: 'POST'
  }).end();
});
```
@vmarchaud
Copy link
Contributor Author

I believe the PR is good to be landed ?

@addaleax
Copy link
Member

@vmarchaud Yes, thanks for the ping! I’ll start a new CI because that hasn’t happened for the latest (force-)push yet, but otherwise this should be ready.

@nodejs-github-bot
Copy link
Collaborator

@addaleax
Copy link
Member

Landed in 0ebf01d 🎉

@addaleax addaleax closed this Jul 11, 2019
dnalborczyk pushed a commit to dnalborczyk/node that referenced this pull request Jul 11, 2019
```js
const { PerformanceObserver, performance } = require('perf_hooks');
const http = require('http');

const obs = new PerformanceObserver((items) => {
  const entry = items.getEntries()[0];
  console.log(entry.name, entry.duration);
});
obs.observe({ entryTypes: ['http'] });

const server = http.Server(function(req, res) {
  server.close();
  res.writeHead(200);
  res.end('hello world\n');
});

server.listen(0, function() {
  const req = http.request({
    port: this.address().port,
    path: '/',
    method: 'POST'
  }).end();
});
```

PR-URL: nodejs#28486
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
@vmarchaud vmarchaud deleted the http-perf-hooks branch July 12, 2019 07:49
targos pushed a commit that referenced this pull request Jul 20, 2019
```js
const { PerformanceObserver, performance } = require('perf_hooks');
const http = require('http');

const obs = new PerformanceObserver((items) => {
  const entry = items.getEntries()[0];
  console.log(entry.name, entry.duration);
});
obs.observe({ entryTypes: ['http'] });

const server = http.Server(function(req, res) {
  server.close();
  res.writeHead(200);
  res.end('hello world\n');
});

server.listen(0, function() {
  const req = http.request({
    port: this.address().port,
    path: '/',
    method: 'POST'
  }).end();
});
```

PR-URL: #28486
Reviewed-By: Anna Henningsen <anna@addaleax.net>
Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>
This was referenced Jul 23, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
author ready PRs that have at least one approval, no pending requests for changes, and a CI started. c++ Issues and PRs that require attention from people who are familiar with C++. http Issues or PRs related to the http subsystem. perf_hooks Issues and PRs related to the implementation of the Performance Timing API.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

6 participants