Skip to content

False response errored messages #338

@szegheo

Description

@szegheo

Prerequisites

  • I have written a descriptive issue title
  • I have searched existing issues to ensure the regression has not already been reported

Last working version

4.23.2

Stopped working in version

4.24.0

Node.js version

18

Operating system

Linux

Operating system version (i.e. 20.04, 11.3, 10)

Ubuntu 22.04.3 LTS

💥 Regression Report

In our Fastify server we forward all the API requests from the frontend to another micro-service with a global proxy handler routine. We have only one PUT endpoint, and starting from Fastify v4.24.0, every call to this PUT (204) endpoint raises a false "response errored" warning log. However, this proxied PUT request is processed fine on the target, and examining the Fastify logs it shows that everything went normal, except the last line here:

docker logs 4e2a955d0429 |grep "req-3i"
{"level":30,"time":1702909961244,"pid":1,"hostname":"4e2a955d0429","reqId":"req-3i","req":{"method":"PUT","url":"/api/foo-api/api/foo/lock/400003237","hostname":"localhost:5000","remoteAddress":"172.240.61.1","remotePort":41968},"msg":"incoming request"}
{"level":30,"time":1702909961246,"pid":1,"hostname":"4e2a955d0429","reqId":"req-3i","source":"/api/foo/lock/400003237","msg":"fetching from remote server"}
{"level":30,"time":1702909961312,"pid":1,"hostname":"4e2a955d0429","reqId":"req-3i","msg":"response received"}
{"level":30,"time":1702909961313,"pid":1,"hostname":"4e2a955d0429","reqId":"req-3i","res":{"statusCode":204},"responseTime":69.12243801355362,"msg":"request completed"}
{"level":40,"time":1702909967313,"pid":1,"hostname":"4e2a955d0429","reqId":"req-3i","err":{"type":"FastifyError","message":"HTTP request timed out","stack":"FastifyError: HTTP request timed out\n    at ClientRequest.<anonymous> (/home/app/node_modules/.pnpm/@fastify+reply-from@9.4.0/node_modules/@fastify/reply-from/lib/request.js:130:19)\n    at Object.onceWrapper (node:events:628:28)\n    at ClientRequest.emit (node:events:514:28)\n    at TLSSocket.emitRequestTimeout (node:_http_client:847:9)\n    at Object.onceWrapper (node:events:628:28)\n    at TLSSocket.emit (node:events:526:35)\n    at Socket._onTimeout (node:net:571:8)\n    at listOnTimeout (node:internal/timers:569:17)\n    at process.processTimers (node:internal/timers:512:7)","code":"FST_REPLY_FROM_HTTP_REQUEST_TIMEOUT","name":"FastifyError","statusCode":504},"msg":"response errored"}

All the other GETs and POSTs are working fine with the same preHandler logic, where we basically just decode a cookie and set an Authorization header:

request.headers['Authorization'] = `Bearer ${accessToken}`

I've spent a lot of time on this issue, but still don't know why it happens. On our side I see no reason, and it was fine with versions prior to 4.24.0 (so we've been reverted to 4.23.2). I've double checked that PUT endpoint, there's no response body and the response headers are fine (no content-length). Calling it directly from Postman also runs fine. I've tried to remove all our hooks and as much code as possible, but the warning is always there.

I'm trying to create a reproduction code (no luck as of now), but meanwhile I would kindly ask you to take a look on this. Maybe the changes made to the affected Fastify version will show you some connection. My suspect is this change. What do you think?

Thanks in advance!

Steps to Reproduce

I'm working on it... Unfortunately, my first attempts didn't triggered the issue.
Please see my post below.

Expected Behavior

No "response errored" warns for PUT responses with code 204. As it was before 4.24.0.

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions