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

_obfuscate_sql crashes with null parameter #788

Open
mullman-mission opened this issue Mar 27, 2023 · 8 comments
Open

_obfuscate_sql crashes with null parameter #788

mullman-mission opened this issue Mar 27, 2023 · 8 comments

Comments

@mullman-mission
Copy link

We've recently bumped our newrelic python package from 7.4.0.172 to 8.7.1 and are now frequently encountering exceptions when our Flask application processes HTTP requests.

Description
NOTE: # ( Describe the problem you're encountering. )
[TIP]: # ( Do NOT share sensitive information, whether personal, proprietary, or otherwise! )

2023-03-27 15:35:35,417 newrelic.api.transaction ERROR    Runtime instrumentation error. Exception occurred during exit. Report this issue to New Relic support.
Traceback (most recent call last):
  File ".venv/lib/python3.11/site-packages/newrelic/api/wsgi_application.py", line 681, in _nr_wsgi_application_wrapper_
    result = _WSGIApplicationMiddleware(wrapped, environ, _start_response, transaction)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/api/wsgi_application.py", line 199, in __init__
    self.iterable = self.application(self.request_environ, self.start_response)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/sentry_sdk/integrations/flask.py", line 88, in sentry_patched_wsgi_app
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/sentry_sdk/integrations/wsgi.py", line 144, in __call__
    reraise(*_capture_exception(hub))
  File ".venv/lib/python3.11/site-packages/sentry_sdk/_compat.py", line 60, in reraise
    raise value
  File ".venv/lib/python3.11/site-packages/sentry_sdk/integrations/wsgi.py", line 137, in __call__
    rv = self.app(
         ^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/sentry_sdk/integrations/flask.py", line 88, in <lambda>
    return SentryWsgiMiddleware(lambda *a, **kw: old_app(self, *a, **kw))(
                                                 ^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 2551, in __call__
    return self.wsgi_app(environ, start_response)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/werkzeug/middleware/proxy_fix.py", line 187, in __call__
    return self.app(environ, start_response)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "services/web/flask/flask_sockets.py", line 38, in __call__
    return self.wsgi_app(environ, start_response)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/api/wsgi_application.py", line 577, in _nr_wsgi_application_wrapper_
    return wrapped(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 2531, in wsgi_app
    response = self.handle_exception(e)
               ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_cors/extension.py", line 165, in wrapped_function
    return cors_after_request(app.make_response(f(*args, **kwargs)))
                                                ^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/hooks/framework_flask.py", line 148, in _nr_wrapper_Flask_handle_exception_
    return FunctionTraceWrapper(wrapped, name=name)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/api/function_trace.py", line 166, in literal_wrapper
    return wrapped(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 2528, in wsgi_app
    response = self.full_dispatch_request()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 1825, in full_dispatch_request
    rv = self.handle_user_exception(e)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_restx/api.py", line 674, in error_router
    return original_handler(e)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_cors/extension.py", line 165, in wrapped_function
    return cors_after_request(app.make_response(f(*args, **kwargs)))
                                                ^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/hooks/framework_flask.py", line 148, in _nr_wrapper_Flask_handle_exception_
    return FunctionTraceWrapper(wrapped, name=name)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/api/function_trace.py", line 166, in literal_wrapper
    return wrapped(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 1823, in full_dispatch_request
    rv = self.dispatch_request()
         ^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/app.py", line 1799, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/hooks/framework_flask.py", line 82, in _nr_wrapper_handler_
    return wrapped(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_login/utils.py", line 290, in decorated_view
    return current_app.ensure_sync(func)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask/views.py", line 107, in view
    return current_app.ensure_sync(self.dispatch_request)(**kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "services/core/gql/csrf_view.py", line 62, in dispatch_request
    return super().dispatch_request()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "services/core/gql/flask_view.py", line 144, in dispatch_request
    response = super().dispatch_request()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/flask_graphql/graphqlview.py", line 82, in dispatch_request
    execution_results, all_params = run_http_query(
                                    ^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/graphql_server/__init__.py", line 136, in run_http_query
    response_promises = [
                        ^
  File ".venv/lib/python3.11/site-packages/graphql_server/__init__.py", line 137, in <listcomp>
    response_executor.execute(
  File ".venv/lib/python3.11/site-packages/graphql/execution/executors/sync.py", line 16, in execute
    return fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/hooks/component_graphqlserver.py", line 42, in wrap_get_response
    with GraphQLOperationTrace() as trace:
  File ".venv/lib/python3.11/site-packages/newrelic/api/time_trace.py", line 186, in __exit__
    self._complete_trace()
  File ".venv/lib/python3.11/site-packages/newrelic/api/time_trace.py", line 490, in _complete_trace
    self.finalize_data(transaction, *exc_data)
  File ".venv/lib/python3.11/site-packages/newrelic/api/graphql_trace.py", line 79, in finalize_data
    self.graphql = graphql = self.formatted[:limit]
                             ^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/api/graphql_trace.py", line 65, in formatted
    return self.statement.formatted(self.graphql_format)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/core/database_utils.py", line 888, in formatted
    return self.obfuscated
           ^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/core/database_utils.py", line 864, in obfuscated
    self._obfuscated = _uncomment_sql(_obfuscate_sql(self.sql,
                                      ^^^^^^^^^^^^^^^^^^^^^^^^
  File ".venv/lib/python3.11/site-packages/newrelic/core/database_utils.py", line 106, in _obfuscate_sql
    sql = quotes_re.sub('?', sql)
          ^^^^^^^^^^^^^^^^^^^^^^^
TypeError: expected string or bytes-like object, got 'NoneType'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File ".venv/lib/python3.11/site-packages/newrelic/api/transaction.py", line 429, in __exit__
    root.complete_root()
  File ".venv/lib/python3.11/site-packages/newrelic/api/transaction.py", line 118, in complete_root
    trace_cache().complete_root(self)
  File ".venv/lib/python3.11/site-packages/newrelic/core/trace_cache.py", line 304, in complete_root
    task_ids = (id(task) for task in all_tasks(self.asyncio))
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: 'NoneType' object is not iterable

Expected Behavior
NOTE: # ( Tell us what you expected to happen. )
For it to not throw an exception

Troubleshooting or NR Diag results
NOTE: # ( Provide any other relevant log data. )
[TIP]: # ( Scrub logs and diagnostic information for sensitive information )

Steps to Reproduce
NOTE: # ( Please be as specific as possible. )
[TIP]: # ( Link a sample application that demonstrates the issue. )
I unfortunately haven't had time to put together a sample app that reproduces this issue and I cannot share the code base behind this. I may be able to find some time this week to do so, though, unless you all have an idea what's going on.

Your Environment
[TIP]: # ( Include as many relevant details about your environment as possible including the running version of New Relic software and any relevant configurations. )
The main players in this scenario seems to be Flask 2.2.3, Flask-SQLAlchemy 3.0.3, and SQLAlchemy 1.4.46. Python 3.11.2.

Additional context
[TIP]: # ( Add any other context about the problem here. For example, relevant community posts or support tickets. )
Sorry this is an extremely dry bug report, let me know if I should include any info on dependency versions that seem related to this crash.

@mullman-mission
Copy link
Author

Update: poked around at this some more, and it seems to only occur when we send a GET request to our GraphQL server which returns GraphiQL, so I think that https://github.com/newrelic/newrelic-python-agent/blob/main/newrelic/hooks/component_graphqlserver.py#L38 should just return wrapped if query is None, or don't hook in to calls other than POST.

@lrafeei
Copy link
Contributor

lrafeei commented Mar 28, 2023

Hello--I cannot seem to be able to replicate this, so would you be able to supply a sample app?

@maroskucera
Copy link

Hello, I too have encountered this error in my application and prepared a sample app:

from flask import Flask
from flask_graphql import GraphQLView

from graphene import ObjectType, String, Schema


class Query(ObjectType):
    hello = String(first_name=String(default_value="stranger"))
    goodbye = String()

    def resolve_hello(root, info, first_name):
        return f"Hello {first_name}!"

    def resolve_goodbye(root, info):
        return "See ya!"


schema = Schema(query=Query)

app = Flask(__name__)

app.add_url_rule(
    "/graphql",
    view_func=GraphQLView.as_view(
        "graphql",
        schema=schema,
        graphiql=True,
    ),
)

if __name__ == "__main__":
    app.run()

I put that in a file called example.py inside a new virtualenv created on an M1 Mac running macOS 13.3 with Python 3.11 installed from the Python website. Inside the virtualenv, I installed dependencies with this

pip install flask flask-graphql graphene newrelic

and ran the app like this

FLASK_DEBUG=True NEW_RELIC_CONFIG_FILE=newrelic.ini newrelic-admin run-program python example.py

I used a newly created New Relic application/service and a default newrelic.ini downloaded for it from the panel. By default, Flask will serve on 127.0.0.1:5000, so I hit 127.0.0.1:5000/graphql. On the first load, it worked (I haven't had time to investigate why it works on first load). But when I refreshed, just like with my app, it crashed with the message mentioned above

...
  File "lib/python3.11/site-packages/newrelic/core/database_utils.py", line 106, in _obfuscate_sql
    sql = quotes_re.sub('?', sql)
          ^^^^^^^^^^^^^^^^^^^^^^^
TypeError: expected string or bytes-like object, got 'NoneType'

The first request after startup, both in my app and in this example, is always okay. It doesn't matter whether it's a browser request to load GraphiQL or an actual GraphQL POST request containing the query. Only after that first request does the error show up on an attempt to load GraphiQL.

I hope this helps 🙂

@stale
Copy link

stale bot commented Aug 12, 2023

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale label Aug 12, 2023
@maroskucera
Copy link

Is there anything I can do to help resolve this? From my limited investigation, what mullman-mission suggested seems to be the cleanest possible solution. Since May, we patch the library on our deployments to do exactly that and encountered no issues. However, patching like this is of course sub-optimal. I can prepare the PR if needed...

@stale stale bot removed the stale label Aug 16, 2023
@terrafied
Copy link

We're still dealing with this error and it's rather annoying. @maroskucera I'd at least love your deployment patch solution.

@maroskucera
Copy link

After each update of the library, we find the wrap_get_response function in the newrelic/hooks/component_graphqlserver.py file in our virtualenv's site-packages and add

if query is None:
    return wrapped(*args, **kwargs)

after

transaction.set_transaction_name(callable_name(wrapped), "GraphQL", priority=10)

which is at line 40 as of v8.11.0. What is noteworthy here is that this stops before creating a trace, which is fine for us. I tried using

if query is None:
    query = ""

and that ran okay as well, that should create a trace if you want/need that. However, I tested it only briefly and only locally.

@kviktor
Copy link

kviktor commented Feb 2, 2024

Not sure if related but we are also seeing the same(ish) error message when our gunicorn workers times out in the newrelic part of the code.

image

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

No branches or pull requests

5 participants