Connection is reset when redirecting a large request to Flask app

[JuanGarcia345]

Hi,

I'm using a standard Flask pattern (described in Flask doc) to dispatch requests by path to different applications and with large requests (~3Mb) the connection is reset.

The minimal working example for the server is (in file server.py for commands below):

#!/usr/bin/env python3

import flask
import threading
import werkzeug


def make_secondary_app():

    blueprint = flask.Blueprint("secondary", __name__)

    app = flask.Flask("secondary")

    @blueprint.route("/", methods=["POST"])
    def entry_secondary():
        request_data = flask.request.get_data().decode()
        return str(len(request_data))

    app.register_blueprint(blueprint)

    return app


class PathDispatcher(object):
    def __init__(self):

        self.lock = threading.Lock()
        self.default_app = flask.Flask("default_server")
        self.json_app = make_secondary_app()

    def get_application(self, prefix):

        with self.lock:

            if prefix == "secondary":
                return self.json_app

            return self.default_app

    def __call__(self, environ, start_response):

        # Get application associated to prefix
        app = self.get_application(werkzeug.wsgi.peek_path_info(environ))

        # Remove prefix from path
        werkzeug.wsgi.pop_path_info(environ)

        # Call real (secondary) application
        return app(environ, start_response)


def make_main_app():
    return PathDispatcher()


if __name__ == "__main__":
    werkzeug.run_simple(
        "127.0.0.1", 5000, make_main_app(), use_debugger=True, use_reloader=True
    )

launched with

gunicorn --bind 127.0.0.1:5000 "server:make_main_app()"

and the request leading to the connection being reset looks like (library requests):

requests.post("http://127.0.0.1:5000/secondary", data={"a": b" " * 10000000})

Package configuration is (as listed by pip):

• certifi 2020.12.5
• chardet 3.0.4
• click 7.1.2
• Flask 1.1.2
• gunicorn 20.0.4
• idna 2.10
• itsdangerous 1.1.0
• Jinja2 2.11.2
• MarkupSafe 1.1.1
• requests 2.25.0
• urllib3 1.26.2
• Werkzeug 1.0.1

with Python 3.9.1 on Linux.

Some further remarks seem important to mention:

• request is handled correctly with Werkzeug server (ie. run_simple),
• launching the secondary application alone (ie. gunicorn --bind 127.0.0.1:5000 "server:make_secondary_app()") works as expected (post request on http://127.0.0.1:5000),
• using --limit-request-line 0 --limit-request-field_size 0 doesn't make any difference and
• there was a quite similar issue with previous versions of urllib3 (see pull request) but not sure it's related.

Thanks for your help!

[benoitc]

Any log to share?

[JuanGarcia345]

On server side, gunicorn --log-level is not that chatty, only the incoming POST request is logged (is there anything else to do?). As for the client exception: client.log.

First exception:

Traceback (most recent call last):
File "/home/work/.pyenv/versions/bug-gunicorn/lib/python3.9/site-packages/urllib3/connectionpool.py", line 699, in urlopen
httplib_response = self._make_request(
File "/home/work/.pyenv/versions/bug-gunicorn/lib/python3.9/site-packages/urllib3/connectionpool.py", line 394, in _make_request
conn.request(method, url, **httplib_request_kw)
File "/home/work/.pyenv/versions/bug-gunicorn/lib/python3.9/site-packages/urllib3/connection.py", line 234, in request
super(HTTPConnection, self).request(method, url, body=body, headers=headers)
File "/home/work/.pyenv/versions/3.9.1/lib/python3.9/http/client.py", line 1255, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/home/work/.pyenv/versions/3.9.1/lib/python3.9/http/client.py", line 1301, in _send_request
self.endheaders(body, encode_chunked=encode_chunked)
File "/home/work/.pyenv/versions/3.9.1/lib/python3.9/http/client.py", line 1250, in endheaders
self._send_output(message_body, encode_chunked=encode_chunked)
File "/home/work/.pyenv/versions/3.9.1/lib/python3.9/http/client.py", line 1049, in _send_output
self.send(chunk)
File "/home/work/.pyenv/versions/3.9.1/lib/python3.9/http/client.py", line 971, in send
self.sock.sendall(data)
ConnectionResetError: [Errno 104] Connection reset by peer

[benoitc]

even if not chatty what does it display at debug log level?

[JuanGarcia345]

Launching with the command line:

gunicorn --bind 127.0.0.1:5000 --limit-request-line 0 --limit-request-field_size 0 --log-level debug  "server:make_main_app()"

gives:

[2021-01-05 12:30:15 +0100] [14672] [DEBUG] Current configuration:
config: None
bind: ['127.0.0.1:5000']
backlog: 2048
workers: 1
worker_class: sync
threads: 1
worker_connections: 1000
max_requests: 0
max_requests_jitter: 0
timeout: 30
graceful_timeout: 30
keepalive: 2
limit_request_line: 0
limit_request_fields: 100
limit_request_field_size: 0
reload: False
reload_engine: auto
reload_extra_files: []
spew: False
check_config: False
preload_app: False
sendfile: None
reuse_port: False
chdir: /home/work/sandbox
daemon: False
raw_env: []
pidfile: None
worker_tmp_dir: None
user: 1000
group: 1000
umask: 0
initgroups: False
tmp_upload_dir: None
secure_scheme_headers: {'X-FORWARDED-PROTOCOL': 'ssl', 'X-FORWARDED-PROTO': 'https', 'X-FORWARDED-SSL': 'on'}
forwarded_allow_ips: ['127.0.0.1']
accesslog: None
disable_redirect_access_to_syslog: False
access_log_format: %(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"
errorlog: -
loglevel: debug
capture_output: False
logger_class: gunicorn.glogging.Logger
logconfig: None
logconfig_dict: {}
syslog_addr: udp://localhost:514
syslog: False
syslog_prefix: None
syslog_facility: user
enable_stdio_inheritance: False
statsd_host: None
dogstatsd_tags:
statsd_prefix:
proc_name: None
default_proc_name: server:make_main_app()
pythonpath: None
paste: None
on_starting: <function OnStarting.on_starting at 0x7f85daf60b80>
on_reload: <function OnReload.on_reload at 0x7f85daf60ca0>
when_ready: <function WhenReady.when_ready at 0x7f85daf60dc0>
pre_fork: <function Prefork.pre_fork at 0x7f85daf60ee0>
post_fork: <function Postfork.post_fork at 0x7f85daef1040>
post_worker_init: <function PostWorkerInit.post_worker_init at 0x7f85daef1160>
worker_int: <function WorkerInt.worker_int at 0x7f85daef1280>
worker_abort: <function WorkerAbort.worker_abort at 0x7f85daef13a0>
pre_exec: <function PreExec.pre_exec at 0x7f85daef14c0>
pre_request: <function PreRequest.pre_request at 0x7f85daef15e0>
post_request: <function PostRequest.post_request at 0x7f85daef1670>
child_exit: <function ChildExit.child_exit at 0x7f85daef1790>
worker_exit: <function WorkerExit.worker_exit at 0x7f85daef18b0>
nworkers_changed: <function NumWorkersChanged.nworkers_changed at 0x7f85daef19d0>
on_exit: <function OnExit.on_exit at 0x7f85daef1af0>
proxy_protocol: False
proxy_allow_ips: ['127.0.0.1']
keyfile: None
certfile: None
ssl_version: 2
cert_reqs: 0
ca_certs: None
suppress_ragged_eofs: True
do_handshake_on_connect: False
ciphers: None
raw_paste_global_conf: []
strip_header_spaces: False
[2021-01-05 12:30:15 +0100] [14672] [INFO] Starting gunicorn 20.0.4
[2021-01-05 12:30:15 +0100] [14672] [DEBUG] Arbiter booted
[2021-01-05 12:30:15 +0100] [14672] [INFO] Listening at: http://127.0.0.1:5000 (14672)
[2021-01-05 12:30:15 +0100] [14672] [INFO] Using worker: sync
[2021-01-05 12:30:15 +0100] [14708] [INFO] Booting worker with pid: 14708
[2021-01-05 12:30:15 +0100] [14672] [DEBUG] 1 workers
[2021-01-05 12:30:22 +0100] [14708] [DEBUG] POST /secondary

Did I miss something?

[tilgovi]

Is this the same as #1733 maybe?

[JuanGarcia345]

Well, I'm using version 20.0.4 which (to my understanding) supports wsgi.input_terminated. On the other hand, I think that the input request is directly dispatched from gunicorn to flask application, I really don't see where the incoming data could be chunked, would it be on the client side?

[tilgovi]

I'm not able to reproduce this locally.

[JuanGarcia345]

Ohh, that's annoying... just to be sure, is the gunicorn command as follows?

gunicorn --bind 127.0.0.1:5000 --limit-request-line 0 --limit-request-field_size 0 --log-level debug "server:make_main_app()"

To avoid a copy error from my side here is the file I'm using (txt extension added to upload)

Could it be an OS issue? I've tested with two different Debian-based Linuces using virtualenvs every time and the issue is still there without any message in the system log.

I've also tried Docker containers with debian:testing (Python 3.9.1), ubuntu:focal (Python 3.8.5) and alpine:latest (Python 3.8.7), for all of them pip list gives:

certifi 2020.12.5
chardet 4.0.0
click 7.1.2
Flask 1.1.2
gunicorn 20.0.4
idna 2.10
itsdangerous 1.1.0
Jinja2 2.11.3
MarkupSafe 1.1.1
requests 2.25.1
urllib3 1.26.3
Werkzeug 1.0.1

Do you want me to try/test anything? Would you mind to share your Python configuration, please?

[Niteshiya]

Flask app gives me 502 error .After 120 seconds it throws error
Flask app on GCP gunicorn config: gunicorn --timeout 72000 -b :$PORT main:app

Python gives the required logs. Its throwing 502 internal server error(bad gateway)