Repository: itamarst/eliot

Issue:
Further improvements to log_call
* [x] Don't log `self` for now (or maybe just blow up when added to methods/classmethods?)
* [x] Log full path (__module__ + __qualname__?) on Python 3 at least
* [x] Construction-time error if include_args doesn't match actual args.

Discussion:

Patch:
diff --git a/eliot/_action.py b/eliot/_action.py
index b15c050..9549ca2 100644
--- a/eliot/_action.py
+++ b/eliot/_action.py
@@ -23,7 +23,7 @@ from pyrsistent import (
     pvector_field,
     pvector, )
 from boltons.funcutils import wraps
-from six import text_type as unicode, integer_types
+from six import text_type as unicode, integer_types, PY3
 
 from ._message import (
     Message,
@@ -896,12 +896,29 @@ def log_call(
                        include_result=include_result)
 
     if action_type is None:
-        action_type = wrapped_function.__name__
+        if PY3:
+            action_type = "{}.{}".format(wrapped_function.__module__,
+                                         wrapped_function.__qualname__)
+        else:
+            action_type = wrapped_function.__name__
+
+    if PY3 and include_args is not None:
+        from inspect import signature
+        sig = signature(wrapped_function)
+        if set(include_args) - set(sig.parameters):
+            raise ValueError(
+                ("include_args ({}) lists arguments not in the "
+                 "wrapped function").format(include_args)
+            )
 
     @wraps(wrapped_function)
     def logging_wrapper(*args, **kwargs):
         callargs = getcallargs(wrapped_function, *args, **kwargs)
 
+        # Remove self is it's included:
+        if "self" in callargs:
+            callargs.pop("self")
+
         # Filter arguments to log, if necessary:
         if include_args is not None:
             callargs = {k: callargs[k] for k in include_args}


Test patch:
diff --git a/eliot/tests/test_action.py b/eliot/tests/test_action.py
index 86eb5e1..699a75e 100644
--- a/eliot/tests/test_action.py
+++ b/eliot/tests/test_action.py
@@ -5,7 +5,7 @@ Tests for L{eliot._action}.
 from __future__ import unicode_literals
 
 import pickle
-from unittest import TestCase
+from unittest import TestCase, skipIf
 from threading import Thread
 from warnings import catch_warnings, simplefilter
 
@@ -1655,6 +1655,9 @@ class LogCallTests(TestCase):
 
     def assert_logged(self, logger, action_type, expected_params, expected_result):
         """Assert that an action of given structure was logged."""
+        if six.PY2:
+            # On Python 2 we don't include the module or class:
+            action_type = action_type.split(".")[-1]
         [tree] = Parser.parse_stream(logger.messages)
         root = tree.root()
         self.assertEqual(root.action_type, action_type)
@@ -1676,7 +1679,7 @@ class LogCallTests(TestCase):
             return 4
 
         myfunc(2, 3)
-        self.assert_logged(logger, u"myfunc",
+        self.assert_logged(logger, self.id() + ".<locals>.myfunc",
                            {u"x": 2, u"y": 3}, 4)
 
     @capture_logging(None)
@@ -1712,7 +1715,7 @@ class LogCallTests(TestCase):
             return 4
 
         myfunc(2, y=5)
-        self.assert_logged(logger, u"myfunc",
+        self.assert_logged(logger, self.id() + ".<locals>.myfunc",
                            {u"x": 2, u"y": 5}, 4)
 
     @capture_logging(None)
@@ -1723,7 +1726,7 @@ class LogCallTests(TestCase):
             return 6
 
         myfunc(2)
-        self.assert_logged(logger, u"myfunc",
+        self.assert_logged(logger, self.id() + ".<locals>.myfunc",
                            {u"x": 2, u"y": 1}, 6)
 
     @capture_logging(None)
@@ -1734,7 +1737,7 @@ class LogCallTests(TestCase):
             return 6
 
         myfunc(2, 3, 4, a=1, b=2)
-        self.assert_logged(logger, u"myfunc",
+        self.assert_logged(logger, self.id() + ".<locals>.myfunc",
                            {u"x": 2, u"y": (3, 4), u"z": {u"a": 1, u"b": 2}},
                            6)
 
@@ -1746,7 +1749,16 @@ class LogCallTests(TestCase):
             return 6
 
         myfunc(2, 3, 4)
-        self.assert_logged(logger, u"myfunc", {u"x": 2, u"z": 4}, 6)
+        self.assert_logged(logger, self.id() + ".<locals>.myfunc",
+                           {u"x": 2, u"z": 4}, 6)
+
+    @skipIf(six.PY2, "Didn't bother implementing safety check on Python 2")
+    def test_wrong_whitelist_args(self):
+        """If C{include_args} doesn't match function, raise an exception."""
+        with self.assertRaises(ValueError):
+            @log_call(include_args=["a", "x", "y"])
+            def f(x, y):
+                pass
 
     @capture_logging(None)
     def test_no_result(self, logger):
@@ -1771,3 +1783,16 @@ class LogCallTests(TestCase):
             for_pickling,
             pickle.loads(pickle.dumps(for_pickling))
         )
+
+    @capture_logging(None)
+    def test_methods(self, logger):
+        """self is not logged."""
+        class C(object):
+            @log_call
+            def f(self, x):
+                pass
+
+        C().f(2)
+        self.assert_logged(logger, self.id() + u".<locals>.C.f", {u"x": 2}, None)
+
+