Changeset 470:e81a69790aa2

Timestamp:

08/28/08 16:27:18 (4 months ago)

Author:

Brian Warner <warner@allmydata.com>

branch:

default

Message:

add code to bridge foolscap log events into twisted. Closes #93.

Files:

• ChangeLog (modified) (1 diff)
• doc/logging.xhtml (modified) (1 diff)
• foolscap/logging/log.py (modified) (4 diffs)
• foolscap/pb.py (modified) (1 diff)
• foolscap/test/test_logging.py (modified) (7 diffs)

ChangeLog

@@ +1 @@
+2008-08-28  Brian Warner  <warner@lothar.com>
+
+        * foolscap/logging/log.py: add bridge-foolscap-logs-to-twisted
+        functionality, set up by either calling bridgeLogsToTwisted(), or
+        by setting the FLOGTOTWISTED environment variable (to anything).
+        The default filter will exclude events below the OPERATIONAL
+        severity level, and those generated by foolscap internals (i.e.
+        facility.startswith("foolscap") ). Closes #93.
+        * foolscap/pb.py (Tub.setOption): update to match
+        * foolscap/test/test_logging.py (Bridge): tests for it
+        (Publish): update to use new APIs
+        * doc/logging.xhtml: docs
+
-2008-08-25  Brian Warner  <warner@lothar.com>
-

doc/logging.xhtml

@@ -670 +670 @@
-method is until its stopService() method is called). TODO: review this
-behavior, we want earlier messages to be bridged too.</p>
+
+<p>To bridge log events in the other direction (i.e. taking foolscap log
+messages and copying them into twisted), use the
+<code>log.bridgeLogsToTwisted()</code> call, or the
+<code>FLOGTOTWISTED</code> environment variable. This is useful to get
+foolscap.logging.log.msg() events copied into <code>twistd.log</code>. The
+default filter only bridges non-noisy events (i.e. those at level OPERATIONAL
+or higher), and does not bridge foolscal internal events.</p>
+
+<p>You might use this if you don't buy into the foolscap logging philosophy
+and really want log events to be continually written out to disk. You might
+also use it if you want a long-term record of operationally-significant
+events, or a record that will survive application crashes which don't get
+handled by the existing Incident-recording mechanism.</p>
+
+<pre class="python">
+from foolscap.logging import log
+log.bridgeLogsToTwisted()
+</pre>
+
-
-<h4>stdlib 'logging' module</h4>

foolscap/logging/log.py

@@ -295 +295 @@
-
-class TwistedLogBridge:
-
+, foolscap_logger=theLogger
-        self.tubID = tubID
+        self.logger = foolscap_logger
-
-        # newer versions of Twisted have a function called
@@ -315 +316 @@
-        #  ['system']: string
-
+        if "from-foolscap" in d:
+            return
-        event = d.copy()
-        event['tubID'] = self.tubID
-        message = twisted_log.textFromEventDict(d)
-        event.pop('message', None)
-
+
+
-
-    def _old_twisted_log_observer(self, d):
+        if "from-foolscap" in d:
+            return
-        event = d.copy()
-        if "format" in d:
@@ -333 +339 @@
-        event.pop('args', None)
-        event['tubID'] = self.tubID
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
-
-class LogFileObserver:
@@ -402 +431 @@
-
-if "FLOGTWISTED" in os.environ:
-
+
+
+
+

foolscap/pb.py

@@ -340 +340 @@
-            self.setLogGathererFURLFile(value)
-        elif name == "bridge-twisted-logs":
-if value:
-    tlb = flog.TwistedLogBridge(self.tubID)
-flog.setTwistedLogBridge(tlb
+assert value is not False, "cannot unbridge twisted logs"
+if value is True:
+return flog.bridgeLogsFromTwisted(self.tubID
-            else:
-
+
+
+
-        elif name == "handle-old-duplicate-connections":
-            if value is True:

foolscap/test/test_logging.py

@@ -349 +349 @@
-    def tearDown(self):
-        publish.Subscription.MAX_QUEUE_SIZE = self.saved_queue_size
-        log.setTwistedLogBridge(None) # disable any bridge still in place
-        d = defer.succeed(None)
-        d.addCallback(lambda res: self.parent.stopService())
@@ -402 +401 @@
-        logport_furl2 = open(furlfile, "r").read().strip()
-        self.failUnlessEqual(logport_furl, logport_furl2)
-
+
+
-
-        t2 = GoodEnoughTub()
-        t2.setServiceParent(self.parent)
-        ob = Observer()
-
-        do_twisted_errors = hasattr(self, "flushLoggedErrors")
-
-        d = t2.getReference(logport_furl)
@@ -425 +423 @@
-                ob.last_received = time.time()
-                log.msg("message 1 here")
-
+
+
-                # switch to generic (no tubid) bridge
-
-
-
+
+
+
+
+
-                log.err(failure.Failure(SampleError("err1")))
-                log.err(SampleError("err2"))
-
-
-
-
-
-
-
+
+
+
+
+
+
+
+
+
+
-            d.addCallback(_emit)
-            # now we wait until the observer has seen nothing for a full
@@ -454 +458 @@
-            def _check_observer(res):
-                msgs = ob.messages
-
-
-
-
+
-                #print msgs
-                self.failUnlessEqual(msgs[0]["message"], "message 1 here")
@@ -479 +480 @@
-                self.failUnless("err2" in str(msgs[5]["failure"]))
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
+
-
-            d.addCallback(_check_observer)
@@ -1049 +1049 @@
-
-    def tearDown(self):
-        log.setTwistedLogBridge(None) # disable any bridge still in place
-        d = defer.succeed(None)
-        d.addCallback(lambda res: self.parent.stopService())
@@ -1847 +1846 @@
-        return d
-
+
+class Bridge(unittest.TestCase):
+    def test_foolscap_to_twisted(self):
+        fl = log.FoolscapLogger()
+        tw = twisted_log.LogPublisher()
+        log.bridgeLogsToTwisted(None, fl, tw)
+        tw_out = []
+        tw.addObserver(tw_out.append)
+        fl_out = []
+        fl.addObserver(fl_out.append)
+
+        fl.msg("one")
+        fl.msg(format="two %(two)d", two=2)
+        fl.msg("three", level=log.NOISY) # should be removed
+        d = flushEventualQueue()
+        def _check(res):
+            self.failUnlessEqual(len(fl_out), 3)
+            self.failUnlessEqual(fl_out[0]["message"], "one")
+            self.failUnlessEqual(fl_out[1]["format"], "two %(two)d")
+            self.failUnlessEqual(fl_out[2]["message"], "three")
+
+            self.failUnlessEqual(len(tw_out), 2)
+            self.failUnlessEqual(tw_out[0]["message"], ("one",))
+            self.failUnless(tw_out[0]["from-foolscap"])
+            self.failUnlessEqual(tw_out[1]["message"], ("two 2",))
+            self.failUnless(tw_out[1]["from-foolscap"])
+
+        d.addCallback(_check)
+        return d
+
+    def test_twisted_to_foolscap(self):
+        fl = log.FoolscapLogger()
+        tw = twisted_log.LogPublisher()
+        log.bridgeLogsFromTwisted(None, tw, fl)
+        tw_out = []
+        tw.addObserver(tw_out.append)
+        fl_out = []
+        fl.addObserver(fl_out.append)
+
+        tw.msg("one")
+        tw.msg(format="two %(two)d", two=2)
+        d = flushEventualQueue()
+        def _check(res):
+            self.failUnlessEqual(len(tw_out), 2)
+            self.failUnlessEqual(tw_out[0]["message"], ("one",))
+            self.failUnlessEqual(tw_out[1]["format"], "two %(two)d")
+            self.failUnlessEqual(tw_out[1]["two"], 2)
+
+            self.failUnlessEqual(len(fl_out), 2)
+            self.failUnlessEqual(fl_out[0]["message"], "one")
+            self.failUnless(fl_out[0]["from-twisted"])
+            self.failUnlessEqual(fl_out[1]["format"], "two %(two)d")
+            self.failUnless(fl_out[1]["from-twisted"])
+
+        d.addCallback(_check)
+        return d
+
+
+    def test_no_loops(self):
+        fl = log.FoolscapLogger()
+        tw = twisted_log.LogPublisher()
+        log.bridgeLogsFromTwisted(None, tw, fl)
+        log.bridgeLogsToTwisted(None, fl, tw)
+        tw_out = []
+        tw.addObserver(tw_out.append)
+        fl_out = []
+        fl.addObserver(fl_out.append)
+
+        tw.msg("one")
+        fl.msg("two")
+
+        d = flushEventualQueue()
+        def _check(res):
+            self.failUnlessEqual(len(tw_out), 2)
+            self.failUnlessEqual(tw_out[0]["message"], ("one",))
+            self.failUnlessEqual(tw_out[1]["message"], ("two",))
+
+            self.failUnlessEqual(len(fl_out), 2)
+            self.failUnlessEqual(fl_out[0]["message"], "one")
+            self.failUnlessEqual(fl_out[1]["message"], "two")
+
+        d.addCallback(_check)
+        return d
+