Upgrading from 5.1.1 to 5.2.0 caused issues with Nginx proxy when ssl response body is large.

[raivil]

Describe the bug

Upgrading from 5.1.1 to 5.2.0 caused one issue with Nginx proxy when the response is larger (44kb).
Requests are successful (status code 200) but the response body was not complete sent to clients.
Clients were seeing the request status as failed and a net::ERR_HTTP2_PROTOCOL_ERROR

Nginx config below and using proxy_http_version http1.1 and http/2.

NGINX started logging errors from the upstream:

2021/02/02 12:57:32 [error] 6#6: *172 upstream sent invalid chunked response while reading upstream,

Reverting to 5.1.1 fixed the issue.

Puma config:

# frozen_string_literal: true

env = ENV.fetch("RAILS_ENV", "development")
environment env

threads ENV.fetch("PUMA_MIN_THREADS", 16), ENV.fetch("PUMA_MAX_THREADS", 64)

if %w(development test).include?(env)
  port ENV.fetch("PORT", 3000)
  plugin :tmp_restart
  return
end

# Keep single mode
workers ENV.fetch("WEB_CONCURRENCY", 0)

rackup "/app/current/config.ru"
directory "/app/current"

ssl_key_path = ENV.fetch("SSL_KEY_PATH", "/path_tofile.key")
ssl_cert_path = ENV.fetch("SSL_CERT_PATH", "/path_tofile.crt")
ssl_bind "0.0.0.0", "3443", key: ssl_key_path, cert: ssl_cert_path
state_path "/app/shared/pids/puma.state"
pidfile "/app/shared/pids/puma.pid" # Cluster PID

Nginx config:
Nginx is configured as a proxy only.

# HTTP 1.1 support
proxy_http_version 1.1;
proxy_buffering off;
proxy_set_header Host $http_host;
proxy_set_header Upgrade $http_upgrade;
proxy_set_header Connection $proxy_connection;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Forwarded-Proto $proxy_x_forwarded_proto;
proxy_set_header X-Forwarded-Port $proxy_x_forwarded_port;
# Mitigate httpoxy attack
proxy_set_header Proxy "";

server {
  server_name   public_url;
  listen 443 ssl http2 ;
  access_log /var/log/nginx/access.log vhost;

client_max_body_size 20m;

location / {
    proxy_pass https://backend_address;
  }

Example request log

*   Trying ip...
* TCP_NODELAY set
* Connected to HOST_URL (IP) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: /etc/ssl/cert.pem
  CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Change cipher spec (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-CHACHA20-POLY1305
* ALPN, server accepted to use h2
* Server certificate:
*  subject: removed
*  start date: May 12 00:00:00 2020 GMT
*  expire date: Aug 15 00:00:00 2022 GMT
*  subjectAltName: host "HOST_URL" matched cert's "removed"
*  issuer: C=US; O=DigiCert Inc; CN=DigiCert SHA2 Secure Server CA
*  SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x7f96c8808200)
> GET /api/endpoint.json HTTP/2
> Host: HOST_URL
> Accept-Encoding: deflate, gzip
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.16; rv:85.0) Gecko/20100101 Firefox/85.0
> Accept: application/json, text/plain, */*
> Accept-Language: en-US,en;q=0.5
> X-Email: email
> X-Token: token
> Origin: https://server_url
> Connection: keep-alive
> Referer: https://server_url/
> TE: Trailers
>
* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
< HTTP/2 200
< server: nginx
< date: Tue, 02 Feb 2021 12:25:22 GMT
< content-type: application/json; charset=utf-8
< x-frame-options: SAMEORIGIN
< x-xss-protection: 1; mode=block
< x-content-type-options: nosniff
< x-download-options: noopen
< x-permitted-cross-domain-policies: none
< referrer-policy: strict-origin-when-cross-origin
< cache-control: no-cache, no-store
< pragma: no-cache
< expires: Fri, 01 Jan 1990 00:00:00 GMT
< etag: W/"61650bf184245a375f0c002a78126a1d"
< x-request-id: c3cba0fe9fbe756026fe3ef224fddca73152599266143943644
< x-runtime: 0.589266
< vary: Origin
< access-control-allow-origin: https://server_url
< access-control-allow-credentials: true
< access-control-allow-methods: GET, POST, OPTIONS, PUT, PATCH, DELETE
< access-control-allow-headers: DNT,X-CM-Token,X-CM-Email,Keep-Alive,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Authorization
< access-control-expose-headers: DNT,X-CustomHeader,Keep-Alive,User-Agent,X-Requested-With,If-Modified-Since,Cache-Control,Content-Type,Content-Range,Range,Authorization
< via: 1.1 google
< alt-svc: clear
<
* HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
* stopped the pause stream!
* Connection #0 to host HOST_URL left intact
curl: (92) HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)
* Closing connection 0

Expected behavior
Requests to complete with full response from the backend.

Desktop (please complete the following information):

• OS: [Linux]
• Puma Version [5.2.0]

What could have changed in Puma that caused this issue?
Could this be a configuration issue?

[MSP-Greg]

@raivil

Thanks for the report. I missed that, it's a one line fix that is already in master.

Should be released as 5.2.1 shortly. See Issue #2542 and PR #2543.

[raivil]

@MSP-Greg awesome! thank you for the fast response!

[MSP-Greg]

Sorry for the bad code, which I wrote and tested. It was a cascade of things, but the main issue was that the test response body used was such that the following was true.

body.length == body.bytesize

The test response body is now using a few multi-byte characters, so that issue can't sneak thru...

[nateberkopec]

@raivil Can you confirm that master fixes the bug for you?

Use master with:

gem 'puma', github: 'puma/puma'

If you can confirm that, I'll feel much more confident releasing the fix as 5.2.1 👍

[raivil]

@nateberkopec yes, sure. I'll provide some feedback later today.

[raivil]

@nateberkopec confirmed it fixed the issue.

[nateberkopec]

Right on. 5.2.1 will release tomorrow.

[gfody]

I'm seeing this same issue on puma 6.4.2