Merge pull request #761 from tahoe-lafs/3365.log-python-3

Fixes ticket:3365

Port allmydata.util.log to Python 3

misc/python3/ratchet-passing

@@ -83,6 +83,14 @@ allmydata.test.test_iputil.ListAddresses.test_list_async_mock_ip_addr
 allmydata.test.test_iputil.ListAddresses.test_list_async_mock_route
 allmydata.test.test_iputil.ListenOnUsed.test_random_port
 allmydata.test.test_iputil.ListenOnUsed.test_specific_port
+allmydata.test.test_log.Log.test_default_facility
+allmydata.test.test_log.Log.test_err
+allmydata.test.test_log.Log.test_grandparent_id
+allmydata.test.test_log.Log.test_no_prefix
+allmydata.test.test_log.Log.test_numming
+allmydata.test.test_log.Log.test_parent_id
+allmydata.test.test_log.Log.test_with_bytes_prefix
+allmydata.test.test_log.Log.test_with_prefix
 allmydata.test.test_netstring.Netstring.test_encode
 allmydata.test.test_netstring.Netstring.test_extra
 allmydata.test.test_netstring.Netstring.test_nested

src/allmydata/hashtree.py

@@ -45,6 +45,8 @@ Written by Connelly Barnes in 2005 and released into the
 public domain  with no warranty of any kind, either expressed
 or implied.  It probably won't make your computer catch on fire,
 or eat  your children, but it might.  Use at your own risk.
+
+Ported to Python 3.
 """
 
 from __future__ import absolute_import

src/allmydata/test/test_log.py

@@ -0,0 +1,156 @@
+"""
+Tests for allmydata.util.log.
+
+Ported to Python 3.
+"""
+
+from __future__ import unicode_literals
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+
+from future.utils import PY2
+if PY2:
+    from builtins import filter, map, zip, ascii, chr, hex, input, next, oct, open, pow, round, super, bytes, dict, list, object, range, str, max, min  # noqa: F401
+
+from twisted.trial import unittest
+from twisted.python.failure import Failure
+
+from foolscap.logging import log
+
+from allmydata.util import log as tahoe_log
+
+
+class SampleError(Exception):
+    pass
+
+
+class Log(unittest.TestCase):
+    def setUp(self):
+        self.messages = []
+
+        def msg(msg, facility, parent, *args, **kwargs):
+            self.messages.append((msg, facility, parent, args, kwargs))
+            return "msg{}".format(len(self.messages))
+
+        self.patch(log, "msg", msg)
+
+    def test_err(self):
+        """Logging with log.err() causes tests to fail."""
+        try:
+            raise SampleError("simple sample")
+        except:
+            f = Failure()
+        tahoe_log.err(format="intentional sample error",
+                      failure=f, level=tahoe_log.OPERATIONAL, umid="wO9UoQ")
+        result = self.flushLoggedErrors(SampleError)
+        self.assertEqual(len(result), 1)
+
+    def test_default_facility(self):
+        """
+        If facility is passed to PrefixingLogMixin.__init__, it is used as
+        default facility.
+        """
+        class LoggingObject1(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject1(facility="defaultfac")
+        obj.log("hello")
+        obj.log("world", facility="override")
+        self.assertEqual(self.messages[-2][1], "defaultfac")
+        self.assertEqual(self.messages[-1][1], "override")
+
+    def test_with_prefix(self):
+        """
+        If prefix is passed to PrefixingLogMixin.__init__, it is used in
+        message rendering.
+        """
+        class LoggingObject4(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject4("fac", prefix="pre1")
+        obj.log("hello")
+        obj.log("world")
+        self.assertEqual(self.messages[-2][0], '<LoggingObject4 #1>(pre1): hello')
+        self.assertEqual(self.messages[-1][0], '<LoggingObject4 #1>(pre1): world')
+
+    def test_with_bytes_prefix(self):
+        """
+        If bytes prefix is passed to PrefixingLogMixin.__init__, it is used in
+        message rendering.
+        """
+        class LoggingObject5(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject5("fac", prefix=b"pre1")
+        obj.log("hello")
+        obj.log("world")
+        self.assertEqual(self.messages[-2][0], '<LoggingObject5 #1>(pre1): hello')
+        self.assertEqual(self.messages[-1][0], '<LoggingObject5 #1>(pre1): world')
+
+    def test_no_prefix(self):
+        """
+        If no prefix is passed to PrefixingLogMixin.__init__, it is not used in
+        message rendering.
+        """
+        class LoggingObject2(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject2()
+        obj.log("hello")
+        obj.log("world")
+        self.assertEqual(self.messages[-2][0], '<LoggingObject2 #1>: hello')
+        self.assertEqual(self.messages[-1][0], '<LoggingObject2 #1>: world')
+
+    def test_numming(self):
+        """
+        Objects inheriting from PrefixingLogMixin get a unique number from a
+        class-specific counter.
+        """
+        class LoggingObject3(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject3()
+        obj2 = LoggingObject3()
+        obj.log("hello")
+        obj2.log("world")
+        self.assertEqual(self.messages[-2][0], '<LoggingObject3 #1>: hello')
+        self.assertEqual(self.messages[-1][0], '<LoggingObject3 #2>: world')
+
+    def test_parent_id(self):
+        """
+        The parent message id can be passed in, otherwise the first message's
+        id is used as the parent.
+
+        This logic is pretty bogus, but that's what the code does.
+        """
+        class LoggingObject1(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject1()
+        result = obj.log("zero")
+        self.assertEqual(result, "msg1")
+        obj.log("one", parent="par1")
+        obj.log("two", parent="par2")
+        obj.log("three")
+        obj.log("four")
+        self.assertEqual([m[2] for m in self.messages],
+                         [None, "par1", "par2", "msg1", "msg1"])
+
+    def test_grandparent_id(self):
+        """
+        If grandparent message id is given, it's used as parent id of the first
+        message.
+        """
+        class LoggingObject1(tahoe_log.PrefixingLogMixin):
+            pass
+
+        obj = LoggingObject1(grandparentmsgid="grand")
+        result = obj.log("zero")
+        self.assertEqual(result, "msg1")
+        obj.log("one", parent="par1")
+        obj.log("two", parent="par2")
+        obj.log("three")
+        obj.log("four")
+        self.assertEqual([m[2] for m in self.messages],
+                         ["grand", "par1", "par2", "msg1", "msg1"])

src/allmydata/test/test_util.py

@@ -5,13 +5,11 @@ import os, time, sys
 import yaml
 
 from twisted.trial import unittest
-from twisted.python.failure import Failure
 
 from allmydata.util import idlib, mathutil
 from allmydata.util import fileutil
 from allmydata.util import pollmixin
 from allmydata.util import yamlutil
-from allmydata.util import log as tahoe_log
 from allmydata.util.fileutil import EncryptedTemporaryFile
 from allmydata.test.common_util import ReallyEqualMixin
 
@@ -452,20 +450,6 @@ class EqButNotIs(object):
         return self.x == other
 
 
-class SampleError(Exception):
-    pass
-
-class Log(unittest.TestCase):
-    def test_err(self):
-        try:
-            raise SampleError("simple sample")
-        except:
-            f = Failure()
-        tahoe_log.err(format="intentional sample error",
-                      failure=f, level=tahoe_log.OPERATIONAL, umid="wO9UoQ")
-        self.flushLoggedErrors(SampleError)
-
-
 class YAML(unittest.TestCase):
     def test_convert(self):
         data = yaml.safe_dump(["str", u"unicode", u"\u1234nicode"])

src/allmydata/util/_python3.py

@@ -34,6 +34,7 @@ PORTED_MODULES = [
     "allmydata.util.hashutil",
     "allmydata.util.humanreadable",
     "allmydata.util.iputil",
+    "allmydata.util.log",
     "allmydata.util.mathutil",
     "allmydata.util.namespace",
     "allmydata.util.netstring",
@@ -56,6 +57,7 @@ PORTED_TEST_MODULES = [
     "allmydata.test.test_hashutil",
     "allmydata.test.test_humanreadable",
     "allmydata.test.test_iputil",
+    "allmydata.test.test_log",
     "allmydata.test.test_netstring",
     "allmydata.test.test_observer",
     "allmydata.test.test_pipeline",

src/allmydata/util/log.py

@@ -1,4 +1,18 @@
-from allmydata.util import nummedobj
+"""
+Logging utilities.
+
+Ported to Python 3.
+"""
+from __future__ import absolute_import
+from __future__ import division
+from __future__ import print_function
+from __future__ import unicode_literals
+
+from future.utils import PY2
+if PY2:
+    from builtins import filter, map, zip, ascii, chr, hex, input, next, oct, open, pow, round, super, bytes, dict, list, object, range, str, max, min  # noqa: F401
+
+from pyutil import nummedobj
 
 from foolscap.logging import log
 from twisted.python import log as tw_log
@@ -36,8 +50,8 @@ class LogMixin(object):
     def log(self, msg, facility=None, parent=None, *args, **kwargs):
         if facility is None:
             facility = self._facility
-        pmsgid = None
+        pmsgid = parent
-        if parent is None:
+        if pmsgid is None:
             pmsgid = self._parentmsgid
             if pmsgid is None:
                 pmsgid = self._grandparentmsgid
@@ -54,6 +68,8 @@ class PrefixingLogMixin(nummedobj.NummedObj, LogMixin):
         LogMixin.__init__(self, facility, grandparentmsgid)
 
         if prefix:
+            if isinstance(prefix, bytes):
+                prefix = prefix.decode("utf-8", errors="replace")
             self._prefix = "%s(%s): " % (self.__repr__(), prefix)
         else:
             self._prefix = "%s: " % (self.__repr__(),)

src/allmydata/util/nummedobj.py

@@ -1,42 +0,0 @@
-import collections, itertools, functools
-
-objnums = collections.defaultdict(itertools.count)
-
-
-@functools.total_ordering
-class NummedObj(object):
-    """
-    This is useful for nicer debug printouts.  Instead of objects of the same class being
-    distinguished from one another by their memory address, they each get a unique number, which
-    can be read as "the first object of this class", "the second object of this class", etc.  This
-    is especially useful because separate runs of a program will yield identical debug output,
-    (assuming that the objects get created in the same order in each run).  This makes it possible
-    to diff outputs from separate runs to see what changed, without having to ignore a difference
-    on every line due to different memory addresses of objects.
-    """
-
-    def __init__(self, klass=None):
-        """
-        @param klass: in which class are you counted?  If default value of `None', then self.__class__ will be used.
-        """
-        if klass is None:
-            klass = self.__class__
-        self._classname = klass.__name__
-
-        self._objid = objnums[self._classname].next()
-
-    def __repr__(self):
-        return "<%s #%d>" % (self._classname, self._objid,)
-
-    def __lt__(self, other):
-        if isinstance(other, NummedObj):
-            return (self._objid, self._classname,) < (other._objid, other._classname,)
-        return NotImplemented
-
-    def __eq__(self, other):
-        if isinstance(other, NummedObj):
-            return (self._objid, self._classname,) == (other._objid, other._classname,)
-        return NotImplemented
-
-    def __hash__(self):
-        return id(self)