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

Async OPTIONS function not being awaited #110

Closed
rafmagns-skepa-dreag opened this Issue Jun 6, 2018 · 16 comments

Comments

Projects
None yet
3 participants
@rafmagns-skepa-dreag
Copy link

rafmagns-skepa-dreag commented Jun 6, 2018

Hi. I have the following error:

<CoroWrapper Tester.options() running at test.py:18, created at /fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py:85> was never yielded from
Coroutine object created at (most recent call last, truncated to 10 last lines):
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic/server.py", line 609, in serve
    loop.run_forever()
  File "/fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py", line 126, in send
    return self.gen.send(value)
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic/app.py", line 556, in handle_request
    response = await response
  File "/fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py", line 110, in __next__
    return self.gen.send(None)
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic_jwt/decorators.py", line 42, in decorated_function
    return await utils.call(f, request, *args, **kwargs)
  File "/fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py", line 110, in __next__
    return self.gen.send(None)
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic_jwt/utils.py", line 44, in call
    fn = fn(*args, **kwargs)
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic/views.py", line 63, in view
    return self.dispatch_request(*args, **kwargs)
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic/views.py", line 46, in dispatch_request
    return handler(request, *args, **kwargs)
  File "/fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py", line 85, in debug_wrapper
    return CoroWrapper(gen, None)
/fidessa/uatutils/Tools/Delivery/.pyenv/versions/3.6.4/lib/python3.6/asyncio/coroutines.py:126: RuntimeWarning: coroutine 'Tester.options' was never awaited
  return self.gen.send(value)

I ran into this issue in my application and was also able to reproduce it with the following code:

from sanic_cors.core import ALL_METHODS
from sanic.views import HTTPMethodView
from sanic.response import text
from sanic_jwt import Authentication, initialize, protected
from sanic import Sanic, Blueprint


class TestMethodView(HTTPMethodView):
    async def options(self, *args, **kwargs):
        return text('ok')

class Tester(TestMethodView):
    decorators = [protected()]

    async def get(self, request):
        return text('ok')

bp = Blueprint('bp')
bp.add_route(Tester.as_view(), '/test', methods=ALL_METHODS)


class CustomAuth(Authentication):
    async def authenticate(self, request, *args, **kwargs):
        return {'username': 'Rich', 'password': 'not secure'}

    async def retrieve_user(self, request, payload, *args, **kwargs):
        if payload:
            user_id = payload.get('username', None)
            passwd = payload.get('password', None)
            return {'username': user_id, 'password': passwd}

    async def extend_payload(self, payload, user=None, *args, **kwargs):
        if user:
            payload.update({'extra_info': 'awesome!'})
        return payload


def make_app():
    app = Sanic(__name__)
    app.config.SANIC_JWT_AUTHORIZATION_HEADER_PREFIX = 'JWT'
    app.config.SANIC_JWT_EXPIRATION_DELTA = 360000
    app.config.SANIC_JWT_USER_ID = 'username'

    initialize(app, authentication_class=CustomAuth)
    app.blueprint(bp)
    return app 

make_app().go_fast(debug=True, host='0.0.0.0', port=9000)

I should note that ALL_METHODS from sanic_cors is just a list that contains both 'GET' and 'OPTIONS'

Replication steps:

  1. Log in
  2. Send an OPTIONS request to /test

I'm using

python==3.6.4
sanic-jwt==1.1.0
sanic==0.7.0

I've been able to trace the issue to the call function in sanic-jwt/utils.py. The issue appears to be that somehow the options function isn't registered as a coroutine like the get function is. Maybe this issue needs to go to Sanic? I'm not sure. But the issue only occurs with sanic-jwt because the Sanic code automatically calls functions and then checks to see if they are awaitable. Relevant Sanic code:

                # Run response handler
                response = handler(request, *args, **kwargs)
                if isawaitable(response):
                    response = await response

I was able to solve the issue for myself by changing call to:

async def call(fn, *args, **kwargs):
    if callable(fn):
        fn = fn(*args, **kwargs)
    if inspect.iscoroutinefunction(fn) or inspect.isawaitable(fn):
        fn = await fn                                                                                                                                                                                                                                          
    return fn

I'd be more than happy to raise a PR for this. This is my first gh issue, so please let me know if I do something wrong.

Please let me know if you need any further information.

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jun 7, 2018

That's an interesting issue, @rafmagns-skepa-dreag !

First, we (the team) would like to thank you for choosing sanic-jwt and mostly for having spent all this time and effort to provide us such rich feedback on your issue! 😉

I did test your solution in the current sanic-jwt codebase and, sadly, it breaks our tests. The reason is quite simple: both def or async def functions will return True for callable, hence the reason it is called after the inspect statement, not after, in the utils.call function. Quick example that illustrates this issue:

import inspect


def my_sync_fn():
    print("hello sync!")


async def my_async_fn():
    print("hello async!")


def main():
    if callable(my_sync_fn):
        print("my_sync_fn is callable!")
    else:
        print("my_sync_fn is not callable.")

    if callable(my_async_fn):
        print("my_async_fn is callable!")
    else:
        print("my_async_fn is not callable.")

    if inspect.iscoroutinefunction(my_sync_fn) or inspect.isawaitable(
        my_sync_fn
    ):
        print("my_sync_fn is a coroutine function or awaitable!")
    else:
        print("my_sync_fn is neither a coroutine function or awaitable.")

    if inspect.iscoroutinefunction(my_async_fn) or inspect.isawaitable(
        my_async_fn
    ):
        print("my_async_fn is a coroutine function or awaitable!")
    else:
        print("my_async_fn is neither a coroutine function or awaitable.")


if __name__ == "__main__":
    main()

And the output is:

$ python test-sync-async-inspect.py  
my_sync_fn is callable!
my_async_fn is callable!
my_sync_fn is neither a coroutine function or awaitable.
my_async_fn is a coroutine function or awaitable!

I think we need to find another solution for your problem. @ahopkins , what's your thought about it?

@ahopkins

This comment has been minimized.

Copy link
Owner

ahopkins commented Jun 7, 2018

Hey guys.... I haven't looked to close yet. I'm away for a few days so I will not be back to a computer until Sunday likely. Just wanted to give you a heads up, to let you know I saw it and will weigh in when I am back.

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jun 7, 2018

No problem, @ahopkins ! Take your time ... The only thing that I noticed was this:

class Tester(TestMethodView):
    decorators = [protected()]  # <--- here

Perhaps removing the function call would make it work? I'm just guessing here ...

@rafmagns-skepa-dreag

This comment has been minimized.

Copy link
Author

rafmagns-skepa-dreag commented Jun 7, 2018

Hey @vltr thanks for taking a look! Removing the actual call from the decorator causes the following error:

[2018-06-07 10:04:26 -0400] [21535] [ERROR] Invalid response object for url b'/test', Expected Type: HTTPResponse, Actual Type: <class 'function'>
[2018-06-07 10:04:26 -0400] [21535] [ERROR] Traceback (most recent call last):
  File "/fidessa/uatutils/Tools/Delivery/main_venv/UGUI_UAT-480w8wdy/lib/python3.6/site-packages/sanic/server.py", line 337, in write_response
    response.output(
AttributeError: 'function' object has no attribute 'output'

[2018-06-07 10:04:26 -0400] - (sanic.access)[INFO][1:0]: GET http://ny1-uutp-fdsa-03:9000/test  500 28

Re: both being callable. It makes sense that both would return true for callable. It should be fine to just call the function and then await it if it's an awaitable though, right?

Which test broke? I'm currently in a rather locked down environment and am not able to download pytest or I'd run it myself.

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jun 7, 2018

No problem, @rafmagns-skepa-dreag !

That call in the decorator was an old known problem / bug, I thought it might have made a "surprise comeback" ... I'm glad that the error now is exactly the expected one 😅

As for the tests, I'm already working on another environment, but from what I remember there's a lot of places that this change breaks the code - even though I agree with you that it shouldn't be so sensitive about the order of statements. Anyway, we need to take a further look into it to identify the root cause of the problem (I don't think that utils.call would be it; I think the problem just pass through it. Of course, I might be wrong ...)

@rafmagns-skepa-dreag

This comment has been minimized.

Copy link
Author

rafmagns-skepa-dreag commented Jun 27, 2018

Hey @ahopkins and @vltr, any update on this?

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jun 27, 2018

Hello @rafmagns-skepa-dreag !

Sorry for the void. We (me and @ahopkins) briefly discussed about this issue (and some others), but we had no spare time to see everything through, we are really sorry. I know there must be a solution for this, for now I think you should consider having a copy of sanic-jwt with your workaround (if it is working for you) so it won't stop your development ... Until we find some time to figure everything out. I'm really sorry for this delay.

@rafmagns-skepa-dreag

This comment has been minimized.

Copy link
Author

rafmagns-skepa-dreag commented Jul 9, 2018

@vltr if either your or @ahopkins could point me in the right direction, I'd be happy to take a look at the real underlying issue. Completely understand if this is more of a "we need to figure out a larger road map before this can be worked on" kind of item.

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jul 10, 2018

Hello @rafmagns-skepa-dreag !

Again, I'm really sorry for letting you hanging on this. I'll tackle this now before anything else comes 😉

@vltr vltr self-assigned this Jul 10, 2018

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jul 10, 2018

@rafmagns-skepa-dreag , good news! We have found the problem 🎉

Would you mind if we use a modified version of your snippet as a test case?

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jul 10, 2018

@rafmagns-skepa-dreag in case you need the solution (while we work on to get it on the next release), all you have to do is replace the call function inside utils.py with this version:

async def call(fn, *args, **kwargs):
    if inspect.iscoroutinefunction(fn) or inspect.isawaitable(fn):
        fn = await fn(*args, **kwargs)
    elif callable(fn):
        fn = fn(*args, **kwargs)
        if inspect.isawaitable(fn):
            fn = await fn
    return fn
@rafmagns-skepa-dreag

This comment has been minimized.

Copy link
Author

rafmagns-skepa-dreag commented Jul 11, 2018

Thanks so much @vltr! I'll try out the solution.

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Jul 12, 2018

Great, @rafmagns-skepa-dreag ! Let me know if it worked out for you. I'll leave this issue open to keep track on things to the next release. Would you mind if I use the snippet you provided to write a unit test for this issue?

@vltr vltr reopened this Jul 12, 2018

@rafmagns-skepa-dreag

This comment has been minimized.

Copy link
Author

rafmagns-skepa-dreag commented Jul 26, 2018

Feel free!

@vltr

This comment has been minimized.

Copy link
Collaborator

vltr commented Aug 1, 2018

Great, thanks @rafmagns-skepa-dreag !

@vltr vltr added bug example labels Aug 1, 2018

@ahopkins

This comment has been minimized.

Copy link
Owner

ahopkins commented Aug 5, 2018

This has been added as a test: test_async_options. In addition, see test_preflight.

@ahopkins ahopkins closed this Aug 5, 2018

ahopkins added a commit that referenced this issue Aug 5, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment