Aiohttp: ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2605)

[bortzmeyer]

The following very simple aiohttp client:

#!/usr/bin/env python3

import aiohttp
import asyncio

async def fetch(session, url):
    async with session.get(url) as response:
        print("%s launched" % url)
        return response

async def main():
    async with aiohttp.ClientSession() as session:
        python = await fetch(session, 'https://python.org')
        print("Python: %s" % python.status)

loop = asyncio.get_event_loop()
loop.run_until_complete(main())

produces the following exception:

https://python.org launched
Python: 200
SSL error in data received
protocol: <asyncio.sslproto.SSLProtocol object at 0x7fdec8d42208>
transport: <_SelectorSocketTransport fd=8 read=polling write=<idle, bufsize=0>>
Traceback (most recent call last):
  File "/usr/lib/python3.7/asyncio/sslproto.py", line 526, in data_received
    ssldata, appdata = self._sslpipe.feed_ssldata(data)
  File "/usr/lib/python3.7/asyncio/sslproto.py", line 207, in feed_ssldata
    self._sslobj.unwrap()
  File "/usr/lib/python3.7/ssl.py", line 767, in unwrap
    return self._sslobj.shutdown()
ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2605)

I noticed bug #3477 but it is closed and the problem is still there (I have the latest pip version).

% python --version
Python 3.7.2

% pip show aiohttp
Name: aiohttp
Version: 3.5.4
Summary: Async http client/server framework (asyncio)
Home-page: https://github.com/aio-libs/aiohttp
Author: Nikolay Kim
Author-email: [email protected]
License: Apache 2
Location: /usr/lib/python3.7/site-packages
Requires: chardet, multidict, attrs, async-timeout, yarl
Required-by: 

[aio-libs-bot]

GitMate.io thinks the contributor most likely able to help you is @asvetlov.

Possibly related issues are https://github.com/aio-libs/aiohttp/issues/3502 (BUG. ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify), https://github.com/aio-libs/aiohttp/issues/3477 ("Application data after close notify" regression in 3.5.0 with SSL connection), https://github.com/aio-libs/aiohttp/issues/3052 (SSL with closed connections), https://github.com/aio-libs/aiohttp/issues/2497 (ClientSession keep transferring data after closed), and https://github.com/aio-libs/aiohttp/issues/370 (Server closes connection before sending data).

[asvetlov]

I can reproduce it.
@socketpair ?

[socketpair]

OK, Will try to resolve today.

[asvetlov]

Thanks!

[socketpair]

I can not trigger that on the master branch. The same on 3.5.4

(Python 3.6)

[bortzmeyer]

I can not trigger that on the master branch. The same on 3.5.4

(Python 3.6)

Issue specific to Python 3.7?

Also:

openssl 1.1.1.a
python-pyopenssl 18.0.0

[asvetlov]

That's interesting.
Both master and 3.5 branches fail on Python 3.7 but work fine on Python 3.6

openssl 1.1.1-1ubuntu2.1
pyopenssl version doesn't matter, the library is not used by aiohttp/asyncio

[socketpair]

WOW. Either SSL-related issue, or asyncio race-condition, that resolves differently on different Python versions.

[asvetlov]

3.7 can have more invariant checks.
At least I recall SSL related commits that were landed on 3.7 but not present in 3.6

[socketpair]

Seems, bug not in my changes. Problem is in aborting SSL-connection while it has buffered cleartext data.

My bugs in chunked encoding triggered the same situation: connection was about to close while server had already sent some data. We have to abort connection (instead of graceful closing) when we return connection [with incomplete read response] to a pool.

[socketpair]

I had a glimpse on sources. Seems I can't debug them fast. I don't even figured out where is the problem: in aiohttp, in asyncio or in SSL socket implementation.

What I found: The only place where application data after close notify may happen is:

https://github.com/openssl/openssl/blob/d6c3c1896cf3c0d69bc27da923d63f8130b13ca0/ssl/record/rec_layer_s3.c#L1640

It seems, we should NOT call OpenSSL's ssl3_read_bytes() after shutdown has been sent (or shutdown complete callback has been called?). But I did not find where we send shutdown :( and how it implemented at asyncio side. As I understand, the commit message https://github.com/openssl/openssl/commit/358ffa05cd3a088822c7d06256bc87516d918798 says the opposite...

It seems, it is prohibited now (or always been?) to gracefully close SSL-connections while we have unread data (i.e. peer may sends us data unexpectedly). If that situation is possible we have to abort connection instead of graceful closing.

[asvetlov]

Thanks for sharing your findings

[mjpieters]

For those looking for a work-around to at least silence these exceptions: the traceback seen is output produced by the loop.default_exception_handler() function. You can set your own exception handler (with loop.set_exception_handler()) that just ignores this specific exception if specific conditions are met. I also record the current exception handler and forward the rest to that.

From my main co-routine for the loop, I call ignore_aiohttp_ssl_eror(asyncio.get_running_loop()), which is defined as:

import asyncio
import ssl
import sys

SSL_PROTOCOLS = (asyncio.sslproto.SSLProtocol,)
try:
    import uvloop.loop
except ImportError:
    pass
else:
    SSL_PROTOCOLS = (*SSL_PROTOCOLS, uvloop.loop.SSLProtocol)

def ignore_aiohttp_ssl_eror(loop):
    """Ignore aiohttp #3535 / cpython #13548 issue with SSL data after close

    There is an issue in Python 3.7 up to 3.7.3 that over-reports a
    ssl.SSLError fatal error (ssl.SSLError: [SSL: KRB5_S_INIT] application data
    after close notify (_ssl.c:2609)) after we are already done with the
    connection. See GitHub issues aio-libs/aiohttp#3535 and
    python/cpython#13548.

    Given a loop, this sets up an exception handler that ignores this specific
    exception, but passes everything else on to the previous exception handler
    this one replaces.

    Checks for fixed Python versions, disabling itself when running on 3.7.4+
    or 3.8.

    """
    if sys.version_info >= (3, 7, 4):
        return

    orig_handler = loop.get_exception_handler()

    def ignore_ssl_error(loop, context):
        if context.get("message") in {
            "SSL error in data received",
            "Fatal error on transport",
        }:
            # validate we have the right exception, transport and protocol
            exception = context.get('exception')
            protocol = context.get('protocol')
            if (
                isinstance(exception, ssl.SSLError)
                and exception.reason == 'KRB5_S_INIT'
                and isinstance(protocol, SSL_PROTOCOLS)
            ):
                if loop.get_debug():
                    asyncio.log.logger.debug('Ignoring asyncio SSL KRB5_S_INIT error')
                return
        if orig_handler is not None:
            orig_handler(loop, context)
        else:
            loop.default_exception_handler(context)

    loop.set_exception_handler(ignore_ssl_error)

(Edited to disable on Python 3.7.4 and to support uvloop)

[sosi-deadeye]

Last line should be:
loop.set_exception_handler(ignore_aiohttp_ssl_eror) and not loop.set_exception_handler(ignore_ssl_error)

[mjpieters]

Last line should be:
loop.set_exception_handler(ignore_aiohttp_ssl_eror) and not loop.set_exception_handler(ignore_ssl_error)

No, it should not. ignore_aiohttp_ssl_eror is not an exception handler. It is the function you call from your main coroutine to set the nested ignore_ssl_error exception handler. Which is why I wrote:

From my main co-routine for the loop, I call ignore_aiohttp_ssl_eror(asyncio.get_running_loop())[.]

[mfulgo]

The way I've gotten around this is to ensure that I _always read/consume the response_ before being done with the response. While it's not ideal if you don't actually need the response body, for my use case, it's not burdensome to call await resp.text().

[lilydjwg]

I have a different use-case: I read the headers and head of content for information (like what type the content is and if it's an image, how large it is). So I will not read the entire response.

[asvetlov]

Fixed by upstream: https://github.com/python/cpython/pull/13548

[nazariyv]

Still experiencing this issue.

[mjpieters]

Still experiencing this issue.

Yes, unless you download the Python 3.7 or 3.8 source code from GitHub, you'll still experience this issue. It requires a new Python release before you'll see this fixed, but it is not an aiohttp issue so this ticket is rightfully closed.

Python 3.7.4 will have this fix, and is expected to be available as a final release on 2019-06-24 (so about 4 weeks from today).

There will be a release candidate before that time, or you can try upgrading to 3.8.0b1, expected to be released tomorrow.

[nazariyv]

brilliant. I was about to post my traceback. Thanks for letting me know!

[Pythonic-Rainbow]

Can't wait for 3.7.4 )w(

[elitan]

If you are using docker this might solve it for you:

FROM python:3.8.0b1-alpine3.10

v 3.7.4 is not working.

[Pythonic-Rainbow]

Can anyone confirm whether 3.7.4 is working?

[own3dh4rd]

Can anyone confirm whether 3.7.4 is working?

yep

[Pythonic-Rainbow]

I am using discord.py and theres only once I got this with Python 3.7.3, it rarely happens and I really can't replicate so can't say that myself.

[jorgejesus]

Working with python 3.7.4 sys.version_info(major=3, minor=7, micro=4, releaselevel='final', serial=0) still generates the same problem, using python:3.7.4-alpine:3.9 as dockerfile image

[bsergean]

I also got this as well with python:3.7.4 (but using https://github.com/aaugustin/websockets)

[caa06d9c]

Also using python:3.7.3-alpine3.10

[ShamansCoding]

Same problem with python:3.7.4. For now, I've solved this issue by building a docker image from python:3.7.2

[JayH5]

I did some more digging into this because we were seeing this error in HTTPX. This error also seems to be impacting people in various other libraries.

@socketpair has linked most of the relevant things above already, but here is a summary of what I understand:

• This error type is new to OpenSSL 1.1.1 (older versions won't see this)
• I'm not sure of exactly which Python versions this impacts but can confirm 3.7.0 through to 3.8.0 (despite some comments saying otherwise).
• This error can be caused by a race condition and so may only show up sometimes and how frequently that happens can depend on a number of factors (i.e. is effectively random in practice).
• This error happens when closing a connection that uses SSL (I don't know the aiohttp internals, but an example in asyncio of where this can happen is when calling wait_closed() on a asyncio.StreamWriter instance).
• The reason code of KRB5_S_INIT is wrong. This reason code doesn't even seem to exist in recent versions of OpenSSL. This seems to be an old error code mapping in the Python ssl library to the code 291. The actual reason should be something like APPLICATION_DATA_AFTER_CLOSE_NOTIFY. See the OpenSSL source here.

As annoying as it sounds, this error message is _saying_ exactly what's going on. When you close an SSL connection, the SSL_shutdown call is made to OpenSSL.SSL_shutdown is a pretty complicated function--here are the docs. The first time it is called, this function sends a close_notify message to the peer to signal that it has closed the _write_ half of the connection. The peer can then signal the shutdown of the _read_ half of the connection by sending a close_notify of its own. SSL_shutdown can be called a second time to confirm the peer's close_notify is received.

This second call to SSL_shutdown is where OpenSSL 1.1.1 added a new error code that is returned and causes this error in Python. If we send close_notify but the peer/server sends something back that isn't a close_notify of its own, then this error happens. This is kind of a completely reasonable thing to happen if the server was busy sending data (or we were still busy receiving it) when we called SSL_shutdown. It's also much more likely to happen in async code where we're doing things concurrently and not necessarily reading/writing all the response/request data in single, synchronous calls.

What does this all mean? There may be places/cases in aiohttp (again, I don't know it well) where a connection is closed before all the outstanding data is read from it. As far as I understand--and I am not a security expert so take this with a grain of salt--close_notify calls aren't considered important when using a self-terminated protocol like HTTP. Here is a nice Stack Exchange answer about that. So for HTTP things like aiohttp, it may be fine to catch & ignore this exception.

[SimZhou]

This Thread is super useful for me, thanks!
I resolved this issue by upgrading python version from 3.7.3 into 3.7.5

[VeNoMouS]

So.... do we have a fix for those of us on 3.7.3?!?!?!

[VeNoMouS]

NM... traced my issue to Brotli.. installed brotlippy and all is good, even though I was getting ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify.... which is weird...

[dimaqq]

Fixed by upstream: python/cpython#13548

Could @asvetlov elaborate how the upstream fix applies here, please?
It seems I just can't comprehend this issue and change.

I wrote some silly code that uses h2 directly, starts the connection using asyncio.open_connection(..., ssl=context) and has a context manager that tried to close the connection on exit, which does write_stream.close(); await write_stream.wait_closed() as recommended in the Python docs. This code talks to an nginx container set up with certs, http2, etc. And I hit what appears to be the same error as in this ticket:

Traceback (most recent call last):
  File "/.../simple.py", line 101, in __aexit__
    await self.w.wait_closed()
  File "/.../asyncio/streams.py", line 359, in wait_closed
    await self._protocol._get_close_waiter(self)
  File "/.../asyncio/sslproto.py", line 529, in data_received
    ssldata, appdata = self._sslpipe.feed_ssldata(data)
  File "/.../asyncio/sslproto.py", line 207, in feed_ssldata
    self._sslobj.unwrap()
  File "/.../ssl.py", line 948, in unwrap
    return self._sslobj.shutdown()
ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2730)

Depending on how I massage the code, the error either happens always, or occasionally (data race?).

I'm running this with Python 3.9.0a4 and beginning to suspect that maybe there's more to be fixed upstream...

[dimaqq]

I've opened https://bugs.python.org/issue39951 for my flavour of possibly same issue.

[luni3359]

Is there a way to fix this without changing versions?