headersTimeout on Agent appears to be broken since 6.20.0

[Stono]

Bug Description

Using fetch with an undici agent with configuration such as new Agent({ headersTimeout: 1}) on 6.19.8 would correctly throw a UND_ERR_HEADERS_TIMEOUT error whereas on 6.20.0 and 6.20.1 the request just hangs.

This was caught by some tests we have around our http client that ensures timeouts work, and they started failing after the undici bump.

Reproducible By

As above really.

Expected Behavior

UND_ERR_HEADERS_TIMEOUT to throw on a headers timeout.

Logs & Screenshots

Environment

node v22.5.1 undici v6.20.x

Additional context

[ronag]

Du you have a full repro?

[Stono]

import express from 'express'
import should from 'should'
import { Agent, fetch } from 'undici'

describe.only('undici', function () {
  it('headers timeouts', async () => {
    const app = express()
    app.get('/delayed', (req, res) => {
      setTimeout(() => {
        res.json({ ok: true })
      }, 5_000)
    })
    app.listen(3002)

    const fetchPromise = async () => {
      const dispatcher = new Agent({
        connectTimeout: 5000,
        bodyTimeout: 300000,
        headersTimeout: 1
      })

      const result = await fetch('http://127.0.0.1:3002/delayed', {
        redirect: 'manual',
        headers: { accept: 'application/json' },
        method: 'GET',
        keepalive: true,
        dispatcher
      })
      return result.status
    }
    const timeoutPromise = new Promise((resolve) =>
      setTimeout(() => resolve('undici broken?'), 500)
    )

    const result = await Promise.race([fetchPromise(), timeoutPromise])
    should(result).not.eql('undici broken?')
  })
})

On 6.19.8:

On 6.20.1:

[metcoder95]

The behaviour is indeed changed, I couldn't reproduce it your code in isolation; but I was able to figure out that this might has to be something with the work done for the fast timers.

As, if e.g. headersTimeout is set to 1 and the server takes just a few ms to respond with the headers, undici still treats that response as valid; the difference should be notable to the timeout take effect.

For instance, my guess is that maybe mocha does something with timers that messes the fast timers implementation and causes undici to drift some the expected behaviour.

import { createServer } from 'node:http'
import { once } from 'node:events'
import { Agent, fetch } from './index.js' // main & v6.x behaves the same

const app = createServer((req, res) => {
  setTimeout(() => {
    res.writeHead(200, { 'Content-Type': 'text/plain' })
    res.end('hello world')
  }, 10) // Change to 500 or 1000 to cause a UND_ERR_HEADERS_TIMEOUT
})

app.listen(0)

await once(app, 'listening')

const dispatcher = new Agent({
  connectTimeout: 1,
  bodyTimeout: 1,
  headersTimeout: 1
})

const result = await fetch(`http://127.0.0.1:${app.address().port}/delayed`, {
  redirect: 'manual',
  headers: { accept: 'text/plain' },
  method: 'GET',
  keepalive: true,
  dispatcher
})

console.log(result.status, await result?.text())

Between v6.19 and v6.20 the fast timers were changed. https://github.com/nodejs/undici/compare/v6.19.8...v6.20.1

[Stono]

@metcoder95 sorry for the ridiculously long delay getting back to you.... honestly i pinned undici and forgot about it :|

I'm now trying to upgrade and running into this again, I've actually realised the reason my mocha tests were failing is because they had a timeout(1_000), even with a headersTimeout of 10, the never version of undici never returns faster than 1_000. This is reproducible outside of mocha.

See this example code:

import { once } from 'node:events'
import { createServer } from 'node:http'

import { Agent, fetch } from 'undici'

const app = createServer((req, res) => {
  setTimeout(() => {
    res.writeHead(200, { 'Content-Type': 'text/plain' })
    res.end('hello world')
  }, 5_000)
})

app.listen(3000)

await once(app, 'listening')

const start = new Date().getTime()
const dispatcher = new Agent({
  connectTimeout: 1,
  bodyTimeout: 1,
  headersTimeout: 100
})

try {
  const result = await fetch(`http://127.0.0.1:3000/delayed`, {
    redirect: 'manual',
    headers: { accept: 'text/plain' },
    method: 'GET',
    keepalive: true,
    dispatcher
  })

  console.log(result.status, await result?.text())
} catch(ex) { 
  console.log(ex)
} finally {
  const end = new Date().getTime()
  console.log('time taken', end - start)
}

This does throw UND_ERR_HEADERS_TIMEOUT but time taken is always > 1_000.

On 6.19.8 this code returns time taken as closer to 100, as you'd expect.

[Uzlopak]

Maybe we should change the resolution of the fast timers?

[Stono]

I suppose the question really is how much it matters. For my particular use case, not so much.

However you could argue for someone who had these settings configured low to "fail fast", it's somewhat of an unexpected breaking change in a minor release. But I don't know the broader intent/expectation of these config options for the project or the trade offs that come with making them more accurate.

[metcoder95]

Indeed here the question will be a matter of tradeoffs. Such low timeout is not something common outside of testing, and given that no much issues has been raised around that; maybe the value of changing the resolution agains the value added might not be well amortized.

I'd suggest that, unless this brings more troubles in actual production-like workloads; we should keep it as is for the time being.

[Stono]

I do believe it should at least be documented, perhaps also on the jsdoc for those config items to let people know about the resolution.

[metcoder95]

Good call, would you like to send a PR for that?

[Stono]

I think it's better written by somebody who understands the timer implementation and the intent of the change.