expressjs / response-time

Response time header for node.js
MIT License
477 stars 73 forks source link

Different Response Times #12

Closed ghost closed 6 years ago

ghost commented 6 years ago

Hi,

Why is the response time of the attached header X-Response-Time different from the response time of the responseTime(req, res, time) which are both different to the response time in postman for a get request.

dougwilson commented 6 years ago

Thanks for reporting the issue! I'm not sure why this would be off hand. I can take a look if you can provide code and steps to reproduce the issue so I have something to investigate!

ghost commented 6 years ago

Well one reason is that postman starts its own timer and so there is the clients network latency. Where as i believe this package is the response time from when it receives the request to when it send the response.

But i was suprised that the X-Response-Time and response(req,res,time) were different.

Sorry it is not a simple example, I have been using this package to add response time to my logger.

     app.use(responseTime());

     app.use(responseTime((req: Request, res: Response, time: any) => {

            const logId = uuid();

            console.log(req);

            const requestLog = {
                log_id: logId,
                line_data_method: req.method,
                line_data_path: req.originalUrl,
                line_data_host: req.hostname,
                line_data_url: req.hostname + req.originalUrl,
                message: ".",
            };

            this.log.info({ ...requestLog, ...{ log_type: "request" } });

            res.on("finish", () => {

                // console.log(res);

                const responseLog = {
                    log_id: logId,
                    line_data_statusCode: res.statusCode,
                    line_data_statusMessage: res.statusMessage,
                    line_data_responseTime: time,
                    line_data_responseTimeHeader: res.getHeader('x-response-time'),
                    message: "."
                };

                this.log.info({ ...responseLog, ...{ log_type: "response" } });

            });

        }));
dougwilson commented 6 years ago

Ah, I see what you mean. This is because each instance of responseTime middleware has it's own timer, which is why the times are not exactly the same.