Response time tracking middleware in Express - Step-by-Step Execution

Concept Flow - Response time tracking middleware

Request received

↓

Middleware start timer

↓

Pass control to next middleware/handler

↓

Response sent back

↓

Middleware calculates elapsed time

↓

Log or store response time

↓

End

The middleware starts a timer when a request arrives, lets the request process, then calculates and logs the response time after the response is sent.

Execution Sample

Express

app.use((req, res, next) => {
  const start = Date.now();
  res.on('finish', () => {
    const duration = Date.now() - start;
    console.log(`Response time: ${duration}ms`);
  });
  next();
});

This middleware measures how long it takes to handle a request and logs the response time in milliseconds.

Execution Table

Step	Action	Evaluation	Result
1	Request arrives	Start timer with Date.now()	start = 1000 (example)
2	Set 'finish' event listener	res.on('finish', callback)	Listener registered
3	Call next()	Pass control to next middleware/handler	Request processing continues
4	Response finishes	res emits 'finish' event	Trigger callback
5	Calculate duration	Date.now() - start	duration = 1050 - 1000 = 50ms
6	Log duration	console.log output	Response time: 50ms
7	End	Middleware completes	Response sent with timing logged

💡 Response finished, middleware logged duration and completed

Variable Tracker

Variable	Start	After Step 1	After Step 5	Final
start	undefined	1000	1000	1000
duration	undefined	undefined	50	50

Key Moments - 2 Insights

Why do we use the 'finish' event on the response object?

Because the 'finish' event fires when the response is fully sent, ensuring the timing includes the entire request handling, as shown in execution_table step 4.

Why do we call next() after setting up the 'finish' event?

We call next() to let the request continue processing, but we set up the 'finish' event listener before calling next() to catch when the response ends, as seen in execution_table steps 2 and 3.

Visual Quiz - 3 Questions

Look at the execution table, what is the value of 'duration' at step 5?

A 50ms

B 1000ms

C undefined

D 1050ms

💡 Hint

Check the 'Calculate duration' row in the execution_table where duration is computed as 1050 - 1000.

At which step does the middleware allow the request to continue processing?

A Step 1

B Step 3

C Step 4

D Step 6

💡 Hint

Look at the 'Call next()' action in the execution_table.

If the 'finish' event listener was set after calling next(), what might happen?

A The timer would start too late.

B The response time would be logged twice.

C The listener might miss the 'finish' event and not log the response time.

D The middleware would block the request.

💡 Hint

Refer to key_moments about why the 'finish' event listener is set before next().

Concept Snapshot

Response time middleware in Express:
- Start timer on request arrival
- Use res.on('finish') to detect response end
- Calculate duration = Date.now() - start
- Log or store duration
- Call next() to continue processing
Ensures full request-response timing is captured.

Full Transcript

This middleware tracks how long a request takes in Express. When a request arrives, it records the current time. It then sets a listener on the response's 'finish' event, which fires when the response is fully sent. When 'finish' triggers, it calculates the elapsed time by subtracting the start time from the current time. Finally, it logs the response time in milliseconds. The middleware calls next() after setting up the listener to let the request continue processing, ensuring it catches the response completion. This way, the middleware accurately measures the total time taken to handle the request and send the response.

Practice

1. What is the main purpose of response time tracking middleware in Express?

easy

A. To measure how long each HTTP request takes to complete

B. To modify the request body before processing

C. To handle errors and send error responses

D. To serve static files like images and CSS

Solution

1. Step 1: Understand middleware role

   Response time tracking middleware measures the duration of requests.

2. Step 2: Identify main purpose

   It tracks how long the server takes to respond to each request.

3. Final Answer:

   To measure how long each HTTP request takes to complete -> Option A

4. Quick Check:

   Response time tracking = measuring request duration [OK]

Hint: Middleware timing tracks request duration, not request content [OK]

Common Mistakes:

• Confusing response time tracking with error handling
• Thinking it modifies request data
• Assuming it serves static files

2. Which of the following is the correct way to start measuring time in an Express middleware?

easy

A. const start = setTimeout();

B. const start = Date.now();

C. const start = process.hrtime();

D. const start = new Date().toString();

Solution

1. Step 1: Identify time measurement method

   Date.now() returns the current timestamp in milliseconds, suitable for timing.

2. Step 2: Check other options

   new Date().toString() returns a string, not a number; process.hrtime() returns a tuple, more complex; setTimeout() is for delays, not time capture.

3. Final Answer:

   const start = Date.now(); -> Option B

4. Quick Check:

   Use Date.now() for simple timestamps [OK]

Hint: Use Date.now() for simple time stamps in middleware [OK]

Common Mistakes:

• Using new Date().toString() which returns a string
• Confusing process.hrtime() with Date.now()
• Using setTimeout() incorrectly for timing

3. Given this middleware snippet, what will be logged?

app.use((req, res, next) => {
  const start = Date.now();
  res.on('finish', () => {
    const duration = Date.now() - start;
    console.log(`Request took ${duration}ms`);
  });
  next();
});

medium

A. Logs the time before the request starts processing

B. Logs the time repeatedly during the request

C. Logs the time taken for each request after response finishes

D. Does not log anything because of missing next()

Solution

1. Step 1: Understand event listener on 'finish'

   The 'finish' event triggers after the response is sent, so timing is complete.

2. Step 2: Calculate duration and log

   Duration is current time minus start time, logged once per request.

3. Final Answer:

   Logs the time taken for each request after response finishes -> Option C

4. Quick Check:

   res.on('finish') logs after response ends [OK]

Hint: res.on('finish') runs after response ends for timing [OK]

Common Mistakes:

• Thinking it logs before request processing
• Assuming multiple logs during request
• Forgetting to call next() to continue middleware chain

4. Identify the error in this response time middleware:

app.use((req, res, next) => {
  const start = Date.now();
  res.on('finish', () => {
    const duration = Date.now() - start;
    console.log(`Request took ${duration}ms`);
  });
});

medium

A. Logging inside middleware is not allowed

B. Using Date.now() instead of process.hrtime() causes error

C. res.on('finish') should be res.on('end')

D. Missing call to next(), so request hangs

Solution

1. Step 1: Check middleware flow

   Middleware must call next() to pass control; missing here causes request to hang.

2. Step 2: Validate event and logging

   res.on('finish') is correct event; Date.now() is valid; logging is allowed.

3. Final Answer:

   Missing call to next(), so request hangs -> Option D

4. Quick Check:

   Always call next() in middleware [OK]

Hint: Always call next() to continue middleware chain [OK]

Common Mistakes:

• Forgetting next() call
• Confusing 'finish' with 'end' event
• Thinking Date.now() causes errors

5. You want to log the response time in milliseconds to the console using the format Request took ${duration}ms. Which middleware code correctly does this?

hard

A. app.use((req, res, next) => {
const start = Date.now();
res.on('finish', () => {
const duration = Date.now() - start;
console.log(`Request took ${duration}ms`);
});
next();
});

B. app.use((req, res, next) => {
const start = Date.now();
const duration = Date.now() - start;
console.log(`Request took ${duration}ms`);
next();
});

C. app.use((req, res, next) => {
const start = Date.now();
console.log(`Request took ${Date.now() - start}ms`);
next();
});

D. app.use((req, res, next) => {
const start = Date.now();
res.on('close', () => {
const duration = Date.now() - start;
console.log(`Request took ${duration}ms`);
});
next();
});

Solution

1. Step 1: Understand logging timing

   To capture the full request processing time, record the start time, call next(), and log the duration in the 'finish' event handler which fires after the response is sent.

2. Step 2: Analyze incorrect approaches

   Logging right after starting the timer yields nearly 0ms because handlers haven't executed yet. The 'close' event relates to connection closure, not response completion, and may not fire reliably for timing.

3. Final Answer:

   Uses res.on('finish') to log accurate request duration -> Option A

4. Quick Check:

   res.on('finish') ensures complete request timing [OK]

Hint: Log duration in 'finish' event after response completes [OK]

Common Mistakes:

• Logging before calling next() (duration ~0ms)
• Using 'close' event instead of 'finish'
• Not waiting for response to finish