Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
bortzmeyer opened this issue Jan 14, 2019 · 40 comments
Labels

Comments

@bortzmeyer
Copy link

bortzmeyer commented Jan 14, 2019

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: fafhrd91@gmail.com
License: Apache 2
Location: /usr/lib/python3.7/site-packages
Requires: chardet, multidict, attrs, async-timeout, yarl
Required-by: 
@aio-libs-bot
Copy link

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

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

@asvetlov
Copy link
Member

I can reproduce it.
@socketpair ?

@socketpair
Copy link
Contributor

OK, Will try to resolve today.

@asvetlov
Copy link
Member

Thanks!

@socketpair
Copy link
Contributor

socketpair commented Jan 14, 2019

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

(Python 3.6)

@bortzmeyer
Copy link
Author

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
Copy link
Member

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
Copy link
Contributor

socketpair commented Jan 14, 2019

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

@asvetlov
Copy link
Member

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
Copy link
Contributor

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
Copy link
Contributor

socketpair commented Jan 14, 2019

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 openssl/openssl@358ffa0 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
Copy link
Member

Thanks for sharing your findings

@mjpieters
Copy link
Contributor

mjpieters commented Apr 15, 2019

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
Copy link

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

@mjpieters
Copy link
Contributor

mjpieters commented May 5, 2019

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
Copy link

mfulgo commented May 13, 2019

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
Copy link

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
Copy link
Member

Fixed by upstream: python/cpython#13548

@jorgejesus
Copy link

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
Copy link

bsergean commented Aug 1, 2019

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

@caa06d9c
Copy link

caa06d9c commented Aug 1, 2019

Also using python:3.7.3-alpine3.10

@ShamansCoding
Copy link

ShamansCoding commented Aug 5, 2019

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
Copy link

JayH5 commented Oct 20, 2019

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
Copy link

SimZhou commented Feb 18, 2020

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
Copy link

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

@VeNoMouS
Copy link

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
Copy link
Contributor

dimaqq commented Mar 13, 2020

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
Copy link
Contributor

dimaqq commented Mar 13, 2020

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

@luni3359
Copy link

Is there a way to fix this without changing versions?

michalc added a commit to uktrade/activity-stream that referenced this issue Jul 23, 2020
aio-libs/aiohttp#3535 Suggests that this bump
may fix some SSL-related errors
@flvndh
Copy link

flvndh commented Nov 23, 2020

Getting the same error:

httpx._exceptions.ReadError: [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify (_ssl.c:2746)

using Python 3.8.6 and OpenSSL 1.1.1d.

@webknjaz
Copy link
Member

@flvndh that one is totally unrelated to this and is coming from httpx which we have absolutely nothing to do with.

@webknjaz
Copy link
Member

FWIW posting in a closed issue is not the best way to get new messages noticed. If there's specific issues that still exist, it's best to submit them separately. 🔒

@aio-libs aio-libs locked as off-topic and limited conversation to collaborators Nov 23, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests