storage: improve logging a bit

diff --git a/src/allmydata/storage.py b/src/allmydata/storage.py
index 24e584d18b568ebc06eb2b18bcbbb161816f8cef..758d8bee84ef798ff8a9235fdf654d75a47e3946 100644 (file)
--- a/src/allmydata/storage.py
+++ b/src/allmydata/storage.py
@@ -9,7 +9,7 @@ from zope.interface import implements
 from allmydata.interfaces import RIStorageServer, RIBucketWriter, \
      RIBucketReader, IStorageBucketWriter, IStorageBucketReader, HASH_SIZE, \
      BadWriteEnablerError
-from allmydata.util import fileutil, idlib, mathutil
+from allmydata.util import fileutil, idlib, mathutil, log
 from allmydata.util.assertutil import precondition, _assert
 
 class DataTooLargeError(Exception):
@@ -257,7 +257,7 @@ class MutableShareFile:
     MAX_SIZE = 2*1000*1000*1000 # 2GB, kind of arbitrary
     # TODO: decide upon a policy for max share size
 
-    def __init__(self, filename):
+    def __init__(self, filename, parent=None):
         self.home = filename
         if os.path.exists(self.home):
             # we don't cache anything, just check the magic
@@ -268,7 +268,10 @@ class MutableShareFile:
              data_length, extra_least_offset) = \
              struct.unpack(">32s20s32sQQ", data)
             assert magic == self.MAGIC
+        self.parent = parent # for logging
 
+    def log(self, *args, **kwargs):
+        return self.parent.log(*args, **kwargs)
 
     def create(self, my_nodeid, write_enabler):
         assert not os.path.exists(self.home)
@@ -555,7 +558,7 @@ class MutableShareFile:
 #        f.close()
 #        return data_length
 
-    def check_write_enabler(self, write_enabler):
+    def check_write_enabler(self, write_enabler, si_s):
         f = open(self.home, 'rb+')
         (real_write_enabler, write_enabler_nodeid) = \
                              self._read_write_enabler_and_nodeid(f)
@@ -563,6 +566,11 @@ class MutableShareFile:
         if write_enabler != real_write_enabler:
             # accomodate share migration by reporting the nodeid used for the
             # old write enabler.
+            self.log(format="bad write enabler on SI %(si)s,"
+                     " recorded by nodeid %(nodeid)s",
+                     facility="tahoe.storage",
+                     level=log.WEIRD,
+                     si=si_s, nodeid=idlib.nodeid_b2a(write_enabler_nodeid))
             msg = "The write enabler was recorded by nodeid '%s'." % \
                   (idlib.nodeid_b2a(write_enabler_nodeid),)
             raise BadWriteEnablerError(msg)
@@ -615,11 +623,11 @@ class EmptyShare:
                 break
         return test_good
 
-def create_mutable_sharefile(filename, my_nodeid, write_enabler):
-    ms = MutableShareFile(filename)
+def create_mutable_sharefile(filename, my_nodeid, write_enabler, parent):
+    ms = MutableShareFile(filename, parent)
     ms.create(my_nodeid, write_enabler)
     del ms
-    return MutableShareFile(filename)
+    return MutableShareFile(filename, parent)
 
 
 class StorageServer(service.MultiService, Referenceable):
@@ -640,8 +648,9 @@ class StorageServer(service.MultiService, Referenceable):
         self._active_writers = weakref.WeakKeyDictionary()
         self.measure_size()
 
-    def log(self, msg):
-        #self.parent.log(msg)
+    def log(self, *args, **kwargs):
+        if self.parent:
+            return self.parent.log(*args, **kwargs)
         return
 
     def setNodeID(self, nodeid):
@@ -737,7 +746,7 @@ class StorageServer(service.MultiService, Referenceable):
             header = f.read(32)
             f.close()
             if header[:32] == MutableShareFile.MAGIC:
-                sf = MutableShareFile(filename)
+                sf = MutableShareFile(filename, self)
                 # note: if the share has been migrated, the renew_lease()
                 # call will throw an exception, with information to help the
                 # client update the lease.
@@ -765,7 +774,7 @@ class StorageServer(service.MultiService, Referenceable):
             header = f.read(32)
             f.close()
             if header[:32] == MutableShareFile.MAGIC:
-                sf = MutableShareFile(filename)
+                sf = MutableShareFile(filename, self)
                 # note: if the share has been migrated, the renew_lease()
                 # call will throw an exception, with information to help the
                 # client update the lease.
@@ -857,8 +866,8 @@ class StorageServer(service.MultiService, Referenceable):
                 except ValueError:
                     continue
                 filename = os.path.join(bucketdir, sharenum_s)
-                msf = MutableShareFile(filename)
-                msf.check_write_enabler(write_enabler)
+                msf = MutableShareFile(filename, self)
+                msf.check_write_enabler(write_enabler, si_s)
                 shares[sharenum] = msf
         # write_enabler is good for all existing shares.
 
@@ -917,7 +926,8 @@ class StorageServer(service.MultiService, Referenceable):
         my_nodeid = self.my_nodeid
         fileutil.make_dirs(bucketdir)
         filename = os.path.join(bucketdir, "%d" % sharenum)
-        share = create_mutable_sharefile(filename, my_nodeid, write_enabler)
+        share = create_mutable_sharefile(filename, my_nodeid, write_enabler,
+                                         self)
         return share
 
     def remote_slot_readv(self, storage_index, shares, readv):
@@ -934,7 +944,7 @@ class StorageServer(service.MultiService, Referenceable):
                 continue
             if sharenum in shares or not shares:
                 filename = os.path.join(bucketdir, sharenum_s)
-                msf = MutableShareFile(filename)
+                msf = MutableShareFile(filename, self)
                 datavs[sharenum] = msf.readv(readv)
         return datavs
 

diff --git a/src/allmydata/test/common.py b/src/allmydata/test/common.py
index 80a0dbb23c5b6c6f37f9383020e055a5454ece84..df6b1169e11855ed5c2b7404f6917cf0729efcc5 100644 (file)
--- a/src/allmydata/test/common.py
+++ b/src/allmydata/test/common.py
@@ -3,9 +3,11 @@ import os
 from zope.interface import implements
 from twisted.internet import defer
 from twisted.python import failure
+from twisted.application import service
 from allmydata import uri, dirnode
 from allmydata.interfaces import IURI, IMutableFileNode, IFileNode
 from allmydata.encode import NotEnoughPeersError
+from allmydata.util import log
 
 class FakeCHKFileNode:
     """I provide IFileNode, but all of my data is stored in a class-level
@@ -115,3 +117,7 @@ class NonGridDirectoryNode(dirnode.NewDirectoryNode):
     look inside the dirnodes and check their contents.
     """
     filenode_class = FakeMutableFileNode
+
+class LoggingServiceParent(service.MultiService):
+    def log(self, *args, **kwargs):
+        return log.msg(*args, **kwargs)

diff --git a/src/allmydata/test/test_storage.py b/src/allmydata/test/test_storage.py
index 3571bbe82fe0ed750a92d2ad9545fbed456be819..4538261c9c728781810d3f178c67c24860b374ea 100644 (file)
--- a/src/allmydata/test/test_storage.py
+++ b/src/allmydata/test/test_storage.py
@@ -1,7 +1,6 @@
 
 from twisted.trial import unittest
 
-from twisted.application import service
 from twisted.internet import defer
 from foolscap import Referenceable
 import time, os.path, stat
@@ -11,6 +10,7 @@ from allmydata.util import fileutil, hashutil, idlib
 from allmydata.storage import BucketWriter, BucketReader, \
      WriteBucketProxy, ReadBucketProxy, StorageServer, MutableShareFile
 from allmydata.interfaces import BadWriteEnablerError
+from allmydata.test.common import LoggingServiceParent
 
 class Bucket(unittest.TestCase):
     def make_workdir(self, name):
@@ -178,7 +178,7 @@ class BucketProxy(unittest.TestCase):
 class Server(unittest.TestCase):
 
     def setUp(self):
-        self.sparent = service.MultiService()
+        self.sparent = LoggingServiceParent()
         self._lease_secret = itertools.count()
     def tearDown(self):
         return self.sparent.stopService()
@@ -444,7 +444,7 @@ class Server(unittest.TestCase):
 class MutableServer(unittest.TestCase):
 
     def setUp(self):
-        self.sparent = service.MultiService()
+        self.sparent = LoggingServiceParent()
         self._lease_secret = itertools.count()
     def tearDown(self):
         return self.sparent.stopService()