Repository: scoutapp/scout_apm_python
Pull request #468 (2020-02-05 16:55:42)

Convert user warnings from logging.warnings to warnings.warn
This is the recommended way for Python users to track down deprecations/problems in their code. We should have been using it all along.


Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 066c00e..0b06f15 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -13,8 +13,16 @@
 
 ### Fixed
 
+- Moved some user-facing warnings, such as for deprecated features, from
+  `logging` to `warnings`, so they can be caught during testing
+  ([PR #468](https://github.com/scoutapp/scout_apm_python/pull/468)).
 - Fix Jinja2 asynchronous rendering instrumentation for Jinja2 2.11.0+
   ([PR #462](https://github.com/scoutapp/scout_apm_python/pull/462)).
+- Stop patching `elasticsearch`'s `scripts_painless_context()`, because it has
+  been removed in version 7.5.1
+  ([Issue #454](https://github.com/scoutapp/scout_apm_python/issues/454)).
+- Fix for `elasticsearch` version 7.5.1's change of positional argument order
+  ([Issue #456](https://github.com/scoutapp/scout_apm_python/issues/456)).
 
 ## [2.10.0] 2020-01-02
 
diff --git a/DEVELOPMENT.md b/DEVELOPMENT.md
index 3f2972e..f6bb96e 100644
--- a/DEVELOPMENT.md
+++ b/DEVELOPMENT.md
@@ -58,11 +58,14 @@ Some of the tests require external services to run against. These are specified
 by environment variables. These are:
 
 * `ELASTICSEARCH_URL` - point to a running Elasticsearch instance, e.g.
-  "http://localhost:9200/"
+  "http://localhost:9200/" . You can start it with:
+  `docker run --detach --name elasticsearch --publish 9200:9200 -e "discovery.type=single-node" elasticsearch:7.5.2` .
 * `MONGODB_URL` - point to a running MongoDB instance e.g.
-  "mongodb://localhost:27017/"
+  "mongodb://localhost:27017/" . You can start it with:
+  `docker run --detach --name mongo --publish 27017:27017 mongo:4.0` .
 * `REDIS_URL` - point to a running Redis instance e.g.
-  "redis://localhost:6379/0"
+  "redis://localhost:6379/0" . You can start it with:
+  `docker run --detach --name redis --publish 6379:6379 redis:5` .
 
 You can `export` any of these environment variables and run the respective
 tests with `tox`.
diff --git a/src/scout_apm/compat.py b/src/scout_apm/compat.py
index 9df13fb..050cf6a 100644
--- a/src/scout_apm/compat.py
+++ b/src/scout_apm/compat.py
@@ -63,8 +63,21 @@ else:
     from urlparse import parse_qsl
 
 
+if sys.version_info >= (3, 0):
+
+    def get_pos_args(func):
+        return inspect.getfullargspec(func).args
+
+
+else:
+
+    def get_pos_args(func):
+        return inspect.getargspec(func).args
+
+
 def kwargs_only(func):
     """
+    Source: https://pypi.org/project/kwargs-only/
     Make a function only accept keyword arguments.
     This can be dropped in Python 3 in lieu of:
         def foo(*, bar=default):
diff --git a/src/scout_apm/core/config.py b/src/scout_apm/core/config.py
index ab7acd8..e9c82fe 100644
--- a/src/scout_apm/core/config.py
+++ b/src/scout_apm/core/config.py
@@ -3,6 +3,7 @@ from __future__ import absolute_import, division, print_function, unicode_litera
 
 import logging
 import os
+import warnings
 
 from scout_apm.compat import string_type
 from scout_apm.core import platform_detection
@@ -183,7 +184,7 @@ class Derived(object):
     def derive_core_agent_full_name(self):
         triple = self.config.value("core_agent_triple")
         if not platform_detection.is_valid_triple(triple):
-            logger.warning("Invalid value for core_agent_triple: %s", triple)
+            warnings.warn("Invalid value for core_agent_triple: {}".format(triple))
         return "{name}-{version}-{triple}".format(
             name="scout_apm_core",
             version=self.config.value("core_agent_version"),
diff --git a/src/scout_apm/core/core_agent_manager.py b/src/scout_apm/core/core_agent_manager.py
index a539d23..f213906 100644
--- a/src/scout_apm/core/core_agent_manager.py
+++ b/src/scout_apm/core/core_agent_manager.py
@@ -8,6 +8,7 @@ import os
 import subprocess
 import tarfile
 import time
+import warnings
 
 import requests
 
@@ -88,11 +89,12 @@ class CoreAgentManager(object):
         # Old deprecated name "log_level"
         log_level = scout_config.value("log_level")
         if log_level is not None:
-            logger.warning(
+            warnings.warn(
                 "The config name 'log_level' is deprecated - "
                 + "please use the new name 'core_agent_log_level' instead. "
                 + "This might be configured in your environment variables or "
-                + "framework settings as SCOUT_LOG_LEVEL."
+                + "framework settings as SCOUT_LOG_LEVEL.",
+                DeprecationWarning,
             )
         else:
             log_level = scout_config.value("core_agent_log_level")
diff --git a/src/scout_apm/falcon.py b/src/scout_apm/falcon.py
index a1b09a6..388b66b 100644
--- a/src/scout_apm/falcon.py
+++ b/src/scout_apm/falcon.py
@@ -2,6 +2,7 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 import logging
+import warnings
 
 import falcon
 
@@ -14,11 +15,6 @@ from scout_apm.core.web_requests import (
     track_request_queue_time,
 )
 
-try:
-    from hug.interface import HTTP as HugHTTP
-except ImportError:
-    HugHTTP = None
-
 logger = logging.getLogger(__name__)
 
 # Falcon Middleware docs:
@@ -95,11 +91,12 @@ class ScoutMiddleware(object):
             return
 
         if self.api is None:
-            logger.warning(
+            warnings.warn(
                 (
                     "{}.set_api() should be called before requests begin for"
                     + " more detail."
-                ).format(self.__class__.__name__)
+                ).format(self.__class__.__name__),
+                RuntimeWarning,
             )
             operation = "Controller/{}.{}.{}".format(
                 resource.__module__, resource.__class__.__name__, req.method
diff --git a/src/scout_apm/instruments/elasticsearch.py b/src/scout_apm/instruments/elasticsearch.py
index 08af7bf..8bfdbf4 100644
--- a/src/scout_apm/instruments/elasticsearch.py
+++ b/src/scout_apm/instruments/elasticsearch.py
@@ -6,6 +6,7 @@ from collections import namedtuple
 
 import wrapt
 
+from scout_apm.compat import get_pos_args
 from scout_apm.core.tracked_request import TrackedRequest
 
 try:
@@ -57,7 +58,6 @@ CLIENT_METHODS = [
     ClientMethod("reindex", False),
     ClientMethod("reindex_rethrottle", False),
     ClientMethod("render_search_template", False),
-    ClientMethod("scripts_painless_context", False),
     ClientMethod("scripts_painless_execute", False),
     ClientMethod("scroll", False),
     ClientMethod("search", True),
@@ -86,34 +86,50 @@ def ensure_client_instrumented():
                     wrapped = wrap_client_method(method)
                 setattr(Elasticsearch, name, wrapped)
             except Exception as exc:
-                # Workaround for version 7.5.0 removing scripts_painless_context:
-                # https://github.com/elastic/elasticsearch-py/issues/1098
-                if name != "scripts_painless_context":
-                    logger.warning(
-                        "Unable to instrument elasticsearch.Elasticsearch.%s: %r",
-                        name,
-                        exc,
-                        exc_info=exc,
-                    )
+                logger.warning(
+                    "Unable to instrument elasticsearch.Elasticsearch.%s: %r",
+                    name,
+                    exc,
+                    exc_info=exc,
+                )
 
         have_patched_client = True
 
 
 @wrapt.decorator
 def wrap_client_index_method(wrapped, instance, args, kwargs):
-    def _get_index(index, *args, **kwargs):
-        return index
+    # elasticsearch-py 7.5.1 changed the order of arguments for client methods,
+    # so to be safe we need to inspect the wrapped method's positional
+    # arguments to see if we should pull it from there
+    if "index" in kwargs:
+        index = kwargs["index"]
+    else:
+        unwrapped = wrapped
+        while True:
+            try:
+                unwrapped = unwrapped.__wrapped__
+            except AttributeError:
+                break
 
-    try:
-        index = _get_index(*args, **kwargs)
-    except TypeError:
+        pos_args = get_pos_args(unwrapped)
+        try:
+            index_index = pos_args.index("index")
+        except ValueError:  # pragma: no cover
+            # This guards against the method not accepting an 'index' argument
+            # but they all do - for now
+            index = ""
+        else:
+            try:
+                index = args[index_index - 1]  # subtract 'self'
+            except IndexError:
+                index = ""
+
+    if isinstance(index, (list, tuple)):
+        index = ",".join(index)
+    if index == "":
         index = "Unknown"
-    else:
-        if not index:
-            index = "Unknown"
-        if isinstance(index, (list, tuple)):
-            index = ",".join(index)
     index = index.title()
+
     camel_name = "".join(c.title() for c in wrapped.__name__.split("_"))
     operation = "Elasticsearch/{}/{}".format(index, camel_name)
     tracked_request = TrackedRequest.instance()


Test patch:
diff --git a/tests/integration/core/test_core_agent_manager.py b/tests/integration/core/test_core_agent_manager.py
index 5f9487e..e44a6a1 100644
--- a/tests/integration/core/test_core_agent_manager.py
+++ b/tests/integration/core/test_core_agent_manager.py
@@ -109,20 +109,16 @@ def test_log_level(caplog, core_agent_manager):
     assert caplog.record_tuples == []
 
 
-def test_log_level_deprecated(caplog, core_agent_manager):
+def test_log_level_deprecated(core_agent_manager, recwarn):
     scout_config.set(log_level="foo", core_agent_log_level="bar")
 
     result = core_agent_manager.log_level()
 
     assert result == ["--log-level", "foo"]
-    assert caplog.record_tuples == [
-        (
-            "scout_apm.core.core_agent_manager",
-            logging.WARNING,
-            (
-                "The config name 'log_level' is deprecated - please use the new name "
-                + "'core_agent_log_level' instead. This might be configured in your "
-                + "environment variables or framework settings as SCOUT_LOG_LEVEL."
-            ),
-        )
-    ]
+    assert len(recwarn) == 1
+    warning = recwarn.pop(DeprecationWarning)
+    assert str(warning.message) == (
+        "The config name 'log_level' is deprecated - please use the new name "
+        + "'core_agent_log_level' instead. This might be configured in your "
+        + "environment variables or framework settings as SCOUT_LOG_LEVEL."
+    )
diff --git a/tests/integration/instruments/test_elasticsearch.py b/tests/integration/instruments/test_elasticsearch.py
index 5537a9c..6e2aa04 100644
--- a/tests/integration/instruments/test_elasticsearch.py
+++ b/tests/integration/instruments/test_elasticsearch.py
@@ -36,10 +36,6 @@ def test_all_client_attributes_accounted_for():
 
 @pytest.mark.parametrize(["method_name"], [[m.name] for m in CLIENT_METHODS])
 def test_all_client_methods_exist(method_name):
-    # Workaround for version 7.5.0 removing scripts_painless_context:
-    # https://github.com/elastic/elasticsearch-py/issues/1098
-    if method_name == "scripts_painless_context":
-        return
     assert hasattr(elasticsearch.Elasticsearch, method_name)
 
 
@@ -49,11 +45,6 @@ def test_all_client_methods_exist(method_name):
     [[m.name, m.takes_index_argument] for m in CLIENT_METHODS],
 )
 def test_all_client_methods_match_index_argument(method_name, takes_index_argument):
-    # Workaround for version 7.5.0 removing scripts_painless_context:
-    # https://github.com/elastic/elasticsearch-py/issues/1098
-    if method_name == "scripts_painless_context":
-        return
-
     signature = inspect.signature(getattr(elasticsearch.Elasticsearch, method_name))
 
     if takes_index_argument:
@@ -158,15 +149,11 @@ def test_search(elasticsearch_client, tracked_request):
     assert span.operation == "Elasticsearch/Unknown/Search"
 
 
-@pytest.mark.xfail(
-    reason=(
-        "Broken argument order in Elasticsearch 7.5.1 - see "
-        "https://github.com/scoutapp/scout_apm_python/issues/456"
-    )
-)
+@skip_if_python_2  # Cannot unwrap decorators on Python 2
 def test_search_arg_named_index(elasticsearch_client, tracked_request):
     with pytest.raises(elasticsearch.exceptions.NotFoundError):
-        elasticsearch_client.search("myindex")
+        # body, index
+        elasticsearch_client.search(None, "myindex")
 
     assert len(tracked_request.complete_spans) == 1
     span = tracked_request.complete_spans[0]
@@ -183,7 +170,8 @@ def test_search_kwarg_named_index(elasticsearch_client, tracked_request):
 
 
 def test_search_arg_empty_index(elasticsearch_client, tracked_request):
-    elasticsearch_client.search("")
+    # body, index
+    elasticsearch_client.search(None, "")
 
     assert len(tracked_request.complete_spans) == 1
     span = tracked_request.complete_spans[0]
diff --git a/tests/integration/test_falcon.py b/tests/integration/test_falcon.py
index ed96105..816047e 100644
--- a/tests/integration/test_falcon.py
+++ b/tests/integration/test_falcon.py
@@ -2,7 +2,6 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 import datetime as dt
-import logging
 from contextlib import contextmanager
 
 import falcon
@@ -133,7 +132,7 @@ def test_home(tracked_requests):
     assert tracked_request.complete_spans[1].operation == "Middleware"
 
 
-def test_home_without_set_api(caplog, tracked_requests):
+def test_home_without_set_api(recwarn, tracked_requests):
     with app_with_scout(set_api=False) as app:
         response = TestApp(app).get("/")
 
@@ -149,17 +148,12 @@ def test_home_without_set_api(caplog, tracked_requests):
         == "Controller/tests.integration.test_falcon.HomeResource.GET"
     )
     assert tracked_request.complete_spans[1].operation == "Middleware"
-    falcon_log_tuples = [x for x in caplog.record_tuples if x[0] == "scout_apm.falcon"]
-    assert falcon_log_tuples == [
-        (
-            "scout_apm.falcon",
-            logging.WARNING,
-            (
-                "ScoutMiddleware.set_api() should be called before requests"
-                + " begin for more detail."
-            ),
-        )
-    ]
+    assert len(recwarn) == 1
+    warning = recwarn.pop(RuntimeWarning)
+    assert str(warning.message) == (
+        "ScoutMiddleware.set_api() should be called before requests begin for"
+        + " more detail."
+    )
 
 
 @parametrize_user_ip_headers
diff --git a/tests/unit/core/test_config.py b/tests/unit/core/test_config.py
index f53352d..ca4bae6 100644
--- a/tests/unit/core/test_config.py
+++ b/tests/unit/core/test_config.py
@@ -1,7 +1,6 @@
 # coding=utf-8
 from __future__ import absolute_import, division, print_function, unicode_literals
 
-import logging
 import os
 import re
 import sys
@@ -65,7 +64,7 @@ def test_override_triple(caplog):
     assert caplog.record_tuples == []
 
 
-def test_override_triple_invalid(caplog):
+def test_override_triple_invalid(recwarn):
     bad_triple = "badtriple"
     ScoutConfig.set(core_agent_triple=bad_triple)
     config = ScoutConfig()
@@ -75,13 +74,9 @@ def test_override_triple_invalid(caplog):
         ScoutConfig.reset_all()
 
     assert full_name.endswith(bad_triple)
-    assert caplog.record_tuples == [
-        (
-            "scout_apm.core.config",
-            logging.WARNING,
-            "Invalid value for core_agent_triple: badtriple",
-        )
-    ]
+    assert len(recwarn) == 1
+    warning = recwarn.pop(Warning)
+    assert str(warning.message) == "Invalid value for core_agent_triple: badtriple"
 
 
 def test_get_default_config_value():
diff --git a/tests/unit/test_compat.py b/tests/unit/test_compat.py
index 9294db1..79d9db3 100644
--- a/tests/unit/test_compat.py
+++ b/tests/unit/test_compat.py
@@ -5,7 +5,7 @@ import datetime as dt
 
 import pytest
 
-from scout_apm.compat import ContextDecorator, datetime_to_timestamp, text
+from scout_apm.compat import ContextDecorator, datetime_to_timestamp, get_pos_args, text
 
 
 def test_context_decorator():
@@ -48,3 +48,17 @@ def test_datetime_to_timestamp(given, expected):
 )
 def test_text(given, expected):
     assert text(given) == expected
+
+
+def test_get_pos_args_args():
+    def foo(bar, baz):
+        pass
+
+    assert get_pos_args(foo) == ["bar", "baz"]
+
+
+def test_get_pos_args_kwargs():
+    def foo(bar, baz=None):
+        pass
+
+    assert get_pos_args(foo) == ["bar", "baz"]