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

Response time fixed #23

Closed
wants to merge 1 commit into from
Closed

Conversation

todvora
Copy link

@todvora todvora commented Nov 14, 2017

Hi,
Thank you for this Hapi extension! I find it very useful and it helps me to monitor my microservices.

Recently I discovered a possible bug or strange behaviour. The response times displayed on the status page do not correspond with any other response times measured by other means like developer tools in a browser or good-console logging.

It displays constantly times under 1ms, which is already strange. Especially, when all other tools display response times around 1.5s for my requests.

First, there were a computation flaw in the formula ((diff[0] * 1e3) + diff[1]) * 1e-6 => ((sec * 1e3 + nanos) * 1e-6 => (ms + nanos) * 1e-6. Basically a flaw in groupping of the parts.

When I fixed that, I discovered that the start time is recorded too late, when the computation in routes is already finished, in the onPreResponse hook. So the time diff doesn't say anything about the processing time. But there is a request.info.received variable from Hapi, which marks the request start and we can compute the diff against it.

After that correction, the response time displays realistic values. The presentation has to be adapted slightly and do not display decimal values, but this is just a design issue.

image

Could you please check my changes and consider to merge them? Thank you!


It would be even possible to simplify the middleware-wrapper.js to something like:

server.on('response', function (request) {
    if (request.response.isBoom || request.path === opts.path) {
      return;
    }
    const tookMs = Date.now() - request.info.received;
    onHeadersListener(request.response.statusCode, tookMs, opts.spans);
});

to get even more precise response times, but this would need some additional refactoring.

@coveralls
Copy link

coveralls commented Nov 14, 2017

Coverage Status

Coverage decreased (-1.1%) to 53.012% when pulling 432f778 on todvora:master into 23bf6a0 on ziyasal:master.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants