http2 request to a http1 fastify server hits "default handler for 404 did not catch this, this is likely a fastify bug" #3893

cmawhorter · 2022-05-09T21:09:12Z

Prerequisites

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

Fastify version

3.29.0

Plugin version

No response

Node.js version

14.19.2

Operating system

macOS

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

12.3

Description

This issue has dogged me for as long as I've used fastify across OS's, node versions, and fastify versions.

This message is logged as a warning many times a day: "the default handler for 404 did not catch this, this is likely a fastify bug, please report it"

This particular issue relates to making an http2 request against a http1 fastify server with presumed prior knowledge of an http2 server.

In my case, it is a bot/scanner causing these requests and log entries and I have no control over them.

However, this is a larger issue in that fastify responds regardless of http version used. (Which http versions does fastify support?)

Steps to Reproduce

server:

'use strict'

const fastify = require('fastify')({
  logger: true,
  http2: false
})

fastify.get('/', function (request, reply) {
  reply.code(200).send({ hello: 'world' })
})

fastify.listen(3000)

run this: curl --http2-prior-knowledge -vvvv http://127.0.0.1:3000/

additionally, fastify will respond with http/1.1 regardless of the request version:

telnet 127.0.0.1 3000
GET / HTTP/0.9  # note that HTTP/9.9 also has same result
# result is hello world json

it's possible this is a node bug but i don't have the time atm to research.

Expected Behavior

http2 requests to an http1 server should not lead to warning log entries.

it seems like maybe fastify should respond with 505? though i'm not sure... currently, it just closes the connection, which might be right.

also -- unsupported http versions should be ignored/rejected. fastify will send an http1.1 response to any request for any http version >= 0.0 and <= 9.9

The text was updated successfully, but these errors were encountered:

mcollina · 2022-05-10T06:41:23Z

Good spot! This was totally an unplanned use case.

Would you like to send a Pull Request to address this issue? Remember to add unit tests.

aradwann · 2022-05-15T15:19:19Z

Node.js version
16.14.0

Operating system
Linux (Fedora)

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

steps to reproduce the bug above
I have done the same request against a pure HTTP 1.1 node server as shown below

'use strict'

const http = require('http')
const host = 'localhost'
const port = 3000
const handlerequest = function (req, res) {
  console.log(req)
  console.log(req.httpVersion)
  res.writeHead(200)
  res.end(`Your Request HTTP Version is ${req.httpVersion} 
            with Major ${req.httpVersionMajor} and Minor ${req.httpVersionMinor}`)
}
const server = http.createServer(handlerequest)
server.listen(port, host, () => {
  console.log(`Server is running on http://${host}:${port}`)
})

with:

telnet 127.0.0.1 3000
GET / HTTP/5.6

and the response is

HTTP/1.1 200 OK
Date: Sun, 15 May 2022 15:17:11 GMT
Connection: keep-alive
Keep-Alive: timeout=5
Transfer-Encoding: chunked

46
Your Request HTTP Version is 5.6 
            with Major 5 and Minor 6
0

and tried to do the same request to googe.com

telnet google.com 80  
Trying 216.58.212.110...
Connected to google.com.
Escape character is '^]'.
GET / HTTP/5.6

and the response is

HTTP/1.0 400 Bad Request
Content-Type: text/html; charset=UTF-8
Referrer-Policy: no-referrer
Content-Length: 1555
Date: Sun, 15 May 2022 15:33:33 GMT

<!DOCTYPE html>
<html lang=en>
  <meta charset=utf-8>
  <meta name=viewport content="initial-scale=1, minimum-scale=1, width=device-width">
  <title>Error 400 (Bad Request)!!1</title>
  <style>
    *{margin:0;padding:0}html,code{font:15px/22px arial,sans-serif}html{background:#fff;color:#222;padding:15px}body{margin:7% auto 0;max-width:390px;min-height:180px;padding:30px 0 15px}* > body{background:url(//www.google.com/images/errors/robot.png) 100% 5px no-repeat;padding-right:205px}p{margin:11px 0 22px;overflow:hidden}ins{color:#777;text-decoration:none}a img{border:0}@media screen and (max-width:772px){body{background:none;margin-top:0;max-width:none;padding-right:0}}#logo{background:url(//www.google.com/images/branding/googlelogo/1x/googlelogo_color_150x54dp.png) no-repeat;margin-left:-5px}@media only screen and (min-resolution:192dpi){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat 0% 0%/100% 100%;-moz-border-image:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) 0}}@media only screen and (-webkit-min-device-pixel-ratio:2){#logo{background:url(//www.google.com/images/branding/googlelogo/2x/googlelogo_color_150x54dp.png) no-repeat;-webkit-background-size:100% 100%}}#logo{display:inline-block;height:54px;width:150px}
  </style>
  <a href=//www.google.com/><span id=logo aria-label=Google></span></a>
  <p><b>400.</b> <ins>That’s an error.</ins>
  <p>Your client has issued a malformed or illegal request.  <ins>That’s all we know.</ins>
Connection closed by foreign host.

so I think it's not about Fastify, It may be NodeJS!

mcollina · 2022-05-15T16:49:46Z

The unplanned use case is to provide some info on how to use http1, https and http2 with Node.js.

You can never send a http/2 request to a http/1.1 server (no https).

cmawhorter · 2022-05-15T17:06:45Z

just to reiterate -- this is not my use case and is not something i want. this is bots/scanners hitting my servers and flooding my logs because fastify emits two warning-level log entries every time it happens.

i do not want http2 and i have http2 turned off. fastify is still responding to http2 requests as a http1 server. (likely a node issue h/t @aradwann)

mcollina · 2022-05-15T17:21:29Z

The fix is to change fastify so it does not log in this case.

cmawhorter · 2022-05-15T17:34:40Z

i opened an issue at node but i'd be willing to bet they're going to document and push to userland. FWIW, node http GET / NOTHTTP/1.1 responds with 400 bad request.

mcollina · 2022-05-15T19:16:57Z

which is correct behavior from my point of view.

p16 · 2022-05-17T12:22:36Z

Hi there,
I was looking at the 2 issues raised in this ticket.

Warnings in log

using node 14/15: I see 2 warnings and 1 error in the log
using node >= 16: I see 1 error in the log (no warnings)

The error I'm seeing is

{
    "err": {
        "bytesParsed": 24,
        "code": "HPE_PAUSED_H2_UPGRADE",
        "message": "Parse Error: Pause on PRI/Upgrade",
        "rawPacket": {
            "data": [...],
            "type": "Buffer"
        },
        "reason": "Pause on PRI/Upgrade",
        "stack": "Error: Parse Error: Pause on PRI/Upgrade",
        "type": "Error"
    },
    "level": 10,
    "msg": "client error",
    "pid": 91666,
    "time": 1652787931833
}

Not supported http version

For the http version that returns a 404 instead of a 505 I'm looking into this and I should be able to open a PR.

/cc @mcollina @cmawhorter

mcollina · 2022-05-17T22:21:37Z

Awesome news!

p16 · 2022-05-19T09:08:02Z

The best place to fix this seems to be nodejs itself (as mention by @cmawhorter and discussed in #3909 ). @climba03003 has also propose another approach that seems to reduce the impact of an http version check #3912

climba03003 · 2022-05-19T09:11:47Z

Core fix is optimal.
But, it should not block we fix it first to prevent fourOhFourFallback hiting when the performance impact is small enough (fall between variation).

We can absolutely remove it after the fix from core land. Similarly to #3617 in pair of nodejs/node#41578

mcollina added bug Confirmed bug good first issue Good for newcomers labels May 10, 2022

cmawhorter mentioned this issue May 15, 2022

http module accepts all http versions (e.g. HTTP/9.9) and treats/responds to them as http1 nodejs/node#43115

Closed

fasterbenchmark mentioned this issue May 17, 2022

http module accepts all http versions (e.g. HTTP/9.9) and treats/responds to them as http1 fasterbenchmark/arch#20

Open

p16 mentioned this issue May 18, 2022

Fix 3893: return 505 if the request http version is not supported #3909

Closed

4 tasks

climba03003 mentioned this issue May 19, 2022

feat: http version check #3912

Merged

4 tasks

mcollina closed this as completed in #3912 May 21, 2022

unreleased mentioned this issue Aug 7, 2022

How to detect the HTTP protocol version? (I.e HTTP/1.1, HTTP/2.0) #4181

Closed

2 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

http2 request to a http1 fastify server hits "default handler for 404 did not catch this, this is likely a fastify bug" #3893

http2 request to a http1 fastify server hits "default handler for 404 did not catch this, this is likely a fastify bug" #3893

cmawhorter commented May 9, 2022 •

edited

mcollina commented May 10, 2022

aradwann commented May 15, 2022 •

edited

mcollina commented May 15, 2022

cmawhorter commented May 15, 2022

mcollina commented May 15, 2022

cmawhorter commented May 15, 2022

mcollina commented May 15, 2022

p16 commented May 17, 2022 •

edited

mcollina commented May 17, 2022

p16 commented May 19, 2022

climba03003 commented May 19, 2022 •

edited

http2 request to a http1 fastify server hits "default handler for 404 did not catch this, this is likely a fastify bug" #3893

http2 request to a http1 fastify server hits "default handler for 404 did not catch this, this is likely a fastify bug" #3893

Comments

cmawhorter commented May 9, 2022 • edited

Prerequisites

Fastify version

Plugin version

Node.js version

Operating system

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

Description

Steps to Reproduce

Expected Behavior

mcollina commented May 10, 2022

aradwann commented May 15, 2022 • edited

mcollina commented May 15, 2022

cmawhorter commented May 15, 2022

mcollina commented May 15, 2022

cmawhorter commented May 15, 2022

mcollina commented May 15, 2022

p16 commented May 17, 2022 • edited

mcollina commented May 17, 2022

p16 commented May 19, 2022

climba03003 commented May 19, 2022 • edited

cmawhorter commented May 9, 2022 •

edited

aradwann commented May 15, 2022 •

edited

p16 commented May 17, 2022 •

edited

climba03003 commented May 19, 2022 •

edited