SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY

[stevstrong]

Bug report

Bug description:

Hi,

I have implemented a very simple application using Quart.
OS: WIndows 11
Python version: 3.13.0
The content of main.py:

from quart import Quart, render_template

app = Quart(__name__)

@app.route("/")
async def hello():
    return await render_template("index.html", user={"name":"James","preferred_username":"[email protected]"})


if __name__ == "__main__":
    app.run(debug=True, host="0.0.0.0", port=3000, certfile='cert.pem', keyfile='key.pem')

Server started with py main.py.
Then I visit the web page on https://localhost:3000.
After exactly 5 seconds I get this message:

Unhandled exception in client_connected_cb
handle_traceback: Handle created at (most recent call last):
  File "C:\...\main.py", line 11, in <module>
    app.run(debug=True, host="0.0.0.0", port=3000, certfile='cert.pem', keyfile='key.pem')
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\site-packages\quart\app.py", line 852, in run
    loop.run_until_complete(asyncio.gather(*tasks))
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\base_events.py", line 708, in run_until_complete
    self.run_forever()
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\base_events.py", line 679, in run_forever
    self._run_once()
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\base_events.py", line 2019, in _run_once
    handle._run()
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
transport: <asyncio.sslproto._SSLProtocolTransport object at 0x000001EADB922150>
Traceback (most recent call last):
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\site-packages\hypercorn\asyncio\run.py", line 110, in _server_callback
    await TCPServer(app, loop, config, context, lifespan_state, reader, writer)
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\site-packages\hypercorn\asyncio\tcp_server.py", line 76, in run
    await self._close()
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\site-packages\hypercorn\asyncio\tcp_server.py", line 119, in _close
    await self.writer.wait_closed()
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\streams.py", line 358, in wait_closed
    await self._protocol._get_close_waiter(self)
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\asyncio\sslproto.py", line 648, in _do_shutdown
    self._sslobj.unwrap()
    ~~~~~~~~~~~~~~~~~~~^^
  File "C:\Users\user\AppData\Local\Programs\Python\Python313\Lib\ssl.py", line 955, in unwrap
    return self._sslobj.shutdown()
           ~~~~~~~~~~~~~~~~~~~~~^^
ssl.SSLError: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2706)

CPython versions tested on:

3.13

Operating systems tested on:

Windows

[cjavad]

We also use Quart a lot so just for fun i decided to try it out, and i was able to replicate on Linux 6.11 as well under python 3.13 but not the older 3.12.6 using the same library version of quart and the underlying hypercorn server.

Very interestingly this issue only appears when the request is made from the browser, and not via curl even after attempting different configurations to try to match the browser behavior such as --http2 --parallel --keep-alivetime --tlsv1.3 etc.

For a better example i used <link rel="icon" href="data:,"> Hello world! as my response body to prevent the browser from making multiple requests, but in either case only 1 error was generated.

Inspecting the TLS/TCP communication in wireshark it seems that the browser request makes the server send multiple closing frames exactly 5 seconds later after the initial connection is done.

I suspected this to be a library issue at first but maybe there is a regression in python 3.13 here somewhere, but more testing is needed.

Edit: The issue also appears in Python 3.12 so this might just be a library issue and should probably be directed at hypercorn or quart itself.

[stevstrong]

Thanks for the investigation.
The question is which part of the server initiates the closing requests after 5 seconds.
And then the next question is why this error message happens.
I mean, even there are several closing requests, this should be handled in the SSL module itself as well, I think.

[cjavad]

Without having looked at the hypercorn source code it does appear that a library functionality is running a task that calls shutdown on the TLS connection after 5 seconds. It is VERY odd the issue only occurs when used via a browser, so maybe it is a mismatch in the expected connection lifetime?

I tested it with firefox 131.

[cjavad]

This issue is already tracked (with no real progress it seems) in hypercorn itself pgjones/hypercorn#261. In the previous issue it is noted that it might have been an asyncio bug.

[stevstrong]

The strange thing is that I have the same code running on a Win 2022 server with Py 3.12.2 and there is no issue at all.
I have copied the content of that Python installation folder to the local PC, where the problem exists, but it didn't solve the problem.
Where can I look further?

[stevstrong]

Sorry, I was wrong, the error does not come if I make a request to server from my PC.
If I use Chrome locally on the server, then a timeout error message comes after 30 seconds (identical with the above posted, except the last lines):

File "C:\Users\user\AppData\Local\Programs\Python\Python312\lib\asyncio\stream.py", line 358. in wait_closed
   await self._protocol._get_close_waiter(self)
TimeoutError: SSL shutdown timed out

[cjavad]

I am able to reproduce in python 3.12.2 as well but interestingly i cannot replicate when making requests either via Chrome or my iPhone (Safari) to neither localhost/loopback or a remote address. But it happens consistently with Firefox for me.

Is your certificate chain added to your clients, ei. are they accepted, i am testing with some that are invalid.

[stevstrong]

I am using locally generated cert, as suggested here with the line:
openssl req -new -x509 -key key.pem -out cert.pem -days 365
And I added an exception to Firefox in order to view the page.

[cjavad]

I am setting up a minimal example here with hypercorn and some headless firefox / chrome etc, we should be able to bisect the issue quite efficiently then.

[cjavad]

I have a minimal example here, but the issue does not occur when making the requests in a very naive way with headless firefox / chrome here but still with a browser manually. https://github.com/cjavad/python-hypercorn-issue-125981-repo

It might be wise to move this issue into hypercorn initially until an underlying issue can be identified.

Edit:

Keeping the browser open for longer than 5 seconds triggers the issue.

[stevstrong]

On another laptop Py 3.12.0, the error comes when accessing the page with FF only when I stop the server in cmd window (with CTRL+C).
However, this timeout error comes 30 seconds after request in Edge:

Exception in callback _ProactorBasePipeTransport._call_connection_lost(None)
handle: <Handle _ProactorBasePipeTransport._call_connection_lost(None) created at C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py:109>
source_traceback: Object created at (most recent call last):
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\windows_events.py", line 321, in run_forever
    super().run_forever()
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\base_events.py", line 618, in run_forever
    self._run_once()
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\base_events.py", line 1943, in _run_once
    handle._run()
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\events.py", line 84, in _run
    self._context.run(self._callback, *self._args)
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 325, in _loop_reading
    self._data_received(data, length)
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 260, in _data_received
    self._eof_received()
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 249, in _eof_received
    self.close()
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 109, in close
    self._loop.call_soon(self._call_connection_lost, None)
Traceback (most recent call last):
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\events.py", line 84, in _run
    self._context.run(self._callback, *self._args)
  File "C:\Users\user\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 165, in _call_connection_lost
    self._sock.shutdown(socket.SHUT_RDWR)
ConnectionResetError: [WinError 10054] An existing connection was forcibly closed by the remote host

This might eventually be another issue, I am not sure.

[stevstrong]

Well, now it comes on the other laptop as well:

Task exception was never retrieved
future: <Task finished name='Task-53' coro=<worker_serve.<locals>._server_callback() done, defined at C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\site-packages\hypercorn\asyncio\run.py:104> exception=SSLError(1, '[SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2685)') created at C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\streams.py:248>
source_traceback: Object created at (most recent call last):
  File "C:\Users\Steve\projects\quart_test\main.py", line 12, in <module>
    app.run(debug=True, host="0.0.0.0", port=3000, certfile='cert.pem', keyfile='key.pem')
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\site-packages\quart\app.py", line 852, in run
    loop.run_until_complete(asyncio.gather(*tasks))
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\base_events.py", line 651, in run_until_complete
    self.run_forever()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\windows_events.py", line 321, in run_forever
    super().run_forever()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\base_events.py", line 618, in run_forever
    self._run_once()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\base_events.py", line 1943, in _run_once
    handle._run()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\events.py", line 84, in _run
    self._context.run(self._callback, *self._args)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 325, in _loop_reading
    self._data_received(data, length)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\proactor_events.py", line 265, in _data_received
    protocols._feed_data_to_buffered_proto(self._protocol, data)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\protocols.py", line 210, in _feed_data_to_buffered_proto
    proto.buffer_updated(data_len)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\sslproto.py", line 436, in buffer_updated
    self._do_handshake()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\sslproto.py", line 563, in _do_handshake
    self._on_handshake_complete(None)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\sslproto.py", line 599, in _on_handshake_complete
    self._app_protocol.connection_made(self._get_app_transport())
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\streams.py", line 248, in connection_made
    self._task = self._loop.create_task(res)
Traceback (most recent call last):
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\site-packages\hypercorn\asyncio\run.py", line 110, in _server_callback
    await TCPServer(app, loop, config, context, lifespan_state, reader, writer)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\site-packages\hypercorn\asyncio\tcp_server.py", line 76, in run
    await self._close()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\site-packages\hypercorn\asyncio\tcp_server.py", line 119, in _close
    await self.writer.wait_closed()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\streams.py", line 349, in wait_closed
    await self._protocol._get_close_waiter(self)
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\asyncio\sslproto.py", line 644, in _do_shutdown
    self._sslobj.unwrap()
  File "C:\Users\Steve\AppData\Local\Programs\Python\Python312\Lib\ssl.py", line 921, in unwrap
    return self._sslobj.shutdown()
           ^^^^^^^^^^^^^^^^^^^^^^^
ssl.SSLError: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2685)

And then I cannot even stop the server, CTRL+C does not work, I have to forcibly close the CMD window.

[picnixz]

While I know it's frustrating, but until we have a MWE that is CPython-only, I don't think we can do much here =/. I suggest transfering this issue to hypercorn as it was suggested (but feel free to come back here if the issue can be reproduced without this library and/or something is wrong on our side).

[picnixz]

Closing as wont fix for CPython.