From: Brian Warner Date: Wed, 16 Apr 2008 22:22:30 +0000 (-0700) Subject: mutable WIP: improve logging a bit X-Git-Tag: allmydata-tahoe-1.1.0~240 X-Git-Url: https://git.rkrishnan.org/uri/%3C?a=commitdiff_plain;h=4f07d96667edfa13797bfa5e9a9e73e91d1f0afc;p=tahoe-lafs%2Ftahoe-lafs.git mutable WIP: improve logging a bit --- diff --git a/src/allmydata/mutable/common.py b/src/allmydata/mutable/common.py index 05ea32a2..4e745433 100644 --- a/src/allmydata/mutable/common.py +++ b/src/allmydata/mutable/common.py @@ -1,10 +1,11 @@ from allmydata.util import idlib -MODE_CHECK = "query all peers" -MODE_ANYTHING = "one recoverable version" -MODE_WRITE = "replace all shares, probably" # not for initial creation -MODE_ENOUGH = "enough" +MODE_CHECK = "MODE_CHECK" # query all peers +MODE_ANYTHING = "MODE_ANYTHING" # one recoverable version +MODE_WRITE = "MODE_WRITE" # replace all shares, probably.. not for initial + # creation +MODE_READ = "MODE_READ" class NotMutableError(Exception): pass diff --git a/src/allmydata/mutable/node.py b/src/allmydata/mutable/node.py index 8aecf6ca..52389297 100644 --- a/src/allmydata/mutable/node.py +++ b/src/allmydata/mutable/node.py @@ -12,7 +12,7 @@ from pycryptopp.publickey import rsa from pycryptopp.cipher.aes import AES from publish import Publish -from common import MODE_ENOUGH, MODE_WRITE, UnrecoverableFileError, \ +from common import MODE_READ, MODE_WRITE, UnrecoverableFileError, \ ResponseCache from servermap import ServerMap, ServermapUpdater from retrieve import Retrieve @@ -214,7 +214,7 @@ class MutableFileNode: # methods exposed to the higher-layer application - def update_servermap(self, old_map=None, mode=MODE_ENOUGH): + def update_servermap(self, old_map=None, mode=MODE_READ): servermap = old_map or ServerMap() d = self.obtain_lock() d.addCallback(lambda res: @@ -280,7 +280,7 @@ class MutableFileNode: d.addCallback(_done) return d - def _update_and_retrieve_best(self, old_map=None, mode=MODE_ENOUGH): + def _update_and_retrieve_best(self, old_map=None, mode=MODE_READ): d = self.update_servermap(old_map=old_map, mode=mode) def _updated(smap): goal = smap.best_recoverable_version() diff --git a/src/allmydata/mutable/retrieve.py b/src/allmydata/mutable/retrieve.py index 71a51335..4281ce90 100644 --- a/src/allmydata/mutable/retrieve.py +++ b/src/allmydata/mutable/retrieve.py @@ -452,7 +452,7 @@ class Retrieve: if isinstance(res, failure.Failure): self.log("Retrieve done, with failure", failure=res) else: - self.log("Retrieve done, success!: res=%s" % (res,)) + self.log("Retrieve done, success!") # remember the encoding parameters, use them again next time (seqnum, root_hash, IV, segsize, datalength, k, N, prefix, offsets_tuple) = self.verinfo diff --git a/src/allmydata/mutable/servermap.py b/src/allmydata/mutable/servermap.py index 5a157020..ccfb50d3 100644 --- a/src/allmydata/mutable/servermap.py +++ b/src/allmydata/mutable/servermap.py @@ -7,7 +7,7 @@ from allmydata.util import base32, hashutil, idlib, log from allmydata import storage from pycryptopp.publickey import rsa -from common import MODE_CHECK, MODE_ANYTHING, MODE_WRITE, MODE_ENOUGH, \ +from common import MODE_CHECK, MODE_ANYTHING, MODE_WRITE, MODE_READ, \ DictOfSets, CorruptShareError, NeedMoreDataError from layout import unpack_prefix_and_signature, unpack_header, unpack_share @@ -128,6 +128,18 @@ class ServerMap: seqnums.append(0) return max(seqnums) + def summarize_versions(self): + """Return a string describing which versions we know about.""" + versionmap = self.make_versionmap() + bits = [] + for (verinfo, shares) in versionmap.items(): + (seqnum, root_hash, IV, segsize, datalength, k, N, prefix, + offsets_tuple) = verinfo + shnums = set([shnum for (shnum, peerid, timestamp) in shares]) + bits.append("%d*seq%d-%s" % + (len(shnums), seqnum, base32.b2a(root_hash)[:4])) + return "/".join(bits) + def recoverable_versions(self): """Return a set of versionids, one for each version that is currently recoverable.""" @@ -183,7 +195,7 @@ class ServerMap: pass class ServermapUpdater: - def __init__(self, filenode, servermap, mode=MODE_ENOUGH): + def __init__(self, filenode, servermap, mode=MODE_READ): """I update a servermap, locating a sufficient number of useful shares and remembering where they are located. @@ -218,7 +230,8 @@ class ServermapUpdater: self._need_privkey = True prefix = storage.si_b2a(self._storage_index)[:5] - self._log_number = log.msg("SharemapUpdater(%s): starting" % prefix) + self._log_number = log.msg(format="SharemapUpdater(%(si)s): starting (%(mode)s)", + si=prefix, mode=mode) def log(self, *args, **kwargs): if "parent" not in kwargs: @@ -599,7 +612,7 @@ class ServermapUpdater: if self.mode == MODE_ANYTHING: if recoverable_versions: - self.log("MODE_ANYTHING and %d recoverable versions: done" + self.log("%d recoverable versions: done" % len(recoverable_versions), parent=lp) return self._done() @@ -607,24 +620,23 @@ class ServermapUpdater: if self.mode == MODE_CHECK: # we used self._must_query, and we know there aren't any # responses still waiting, so that means we must be done - self.log("MODE_CHECK: done", - parent=lp) + self.log("done", parent=lp) return self._done() MAX_IN_FLIGHT = 5 - if self.mode == MODE_ENOUGH: + if self.mode == MODE_READ: # if we've queried k+epsilon servers, and we see a recoverable # version, and we haven't seen any unrecoverable higher-seqnum'ed # versions, then we're done. if self._queries_completed < self.num_peers_to_query: - self.log(format="ENOUGH, %(completed)d completed, %(query)d to query: need more", + self.log(format="%(completed)d completed, %(query)d to query: need more", completed=self._queries_completed, query=self.num_peers_to_query, parent=lp) return self._send_more_queries(MAX_IN_FLIGHT) if not recoverable_versions: - self.log("ENOUGH, no recoverable versions: need more", + self.log("no recoverable versions: need more", parent=lp) return self._send_more_queries(MAX_IN_FLIGHT) highest_recoverable = max(recoverable_versions) @@ -635,12 +647,11 @@ class ServermapUpdater: # don't yet see enough shares to recover it. Try harder. # TODO: consider sending more queries. # TODO: consider limiting the search distance - self.log("ENOUGH, evidence of higher seqnum: need more") + self.log("evidence of higher seqnum: need more") return self._send_more_queries(MAX_IN_FLIGHT) # all the unrecoverable versions were old or concurrent with a # recoverable version. Good enough. - self.log("ENOUGH: no higher-seqnum: done", - parent=lp) + self.log("no higher-seqnum: done", parent=lp) return self._done() if self.mode == MODE_WRITE: @@ -650,8 +661,7 @@ class ServermapUpdater: # every server in the world. if not recoverable_versions: - self.log("WRITE, no recoverable versions: need more", - parent=lp) + self.log("no recoverable versions: need more", parent=lp) return self._send_more_queries(MAX_IN_FLIGHT) last_found = -1 @@ -673,7 +683,7 @@ class ServermapUpdater: if last_found != -1: num_not_found += 1 if num_not_found >= self.EPSILON: - self.log("MODE_WRITE: found our boundary, %s" % + self.log("found our boundary, %s" % "".join(states), parent=lp) found_boundary = True @@ -715,8 +725,7 @@ class ServermapUpdater: # if we hit here, we didn't find our boundary, so we're still # waiting for peers - self.log("MODE_WRITE: no boundary yet, %s" % "".join(states), - parent=lp) + self.log("no boundary yet, %s" % "".join(states), parent=lp) return self._send_more_queries(MAX_IN_FLIGHT) # otherwise, keep up to 5 queries in flight. TODO: this is pretty @@ -756,6 +765,7 @@ class ServermapUpdater: self._servermap.last_update_mode = self.mode self._servermap.last_update_time = self._started # the servermap will not be touched after this + self.log("servermap: %s" % self._servermap.summarize_versions()) eventually(self._done_deferred.callback, self._servermap) def _fatal_error(self, f): diff --git a/src/allmydata/test/test_mutable.py b/src/allmydata/test/test_mutable.py index d0f3cb69..a9396890 100644 --- a/src/allmydata/test/test_mutable.py +++ b/src/allmydata/test/test_mutable.py @@ -16,7 +16,7 @@ import sha from allmydata.mutable.node import MutableFileNode from allmydata.mutable.common import DictOfSets, ResponseCache, \ - MODE_CHECK, MODE_ANYTHING, MODE_WRITE, MODE_ENOUGH, UnrecoverableFileError + MODE_CHECK, MODE_ANYTHING, MODE_WRITE, MODE_READ, UnrecoverableFileError from allmydata.mutable.retrieve import Retrieve from allmydata.mutable.publish import Publish from allmydata.mutable.servermap import ServerMap, ServermapUpdater @@ -444,7 +444,7 @@ class Servermap(unittest.TestCase): d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 10)) d.addCallback(lambda res: ms(mode=MODE_WRITE)) d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 10)) - d.addCallback(lambda res: ms(mode=MODE_ENOUGH)) + d.addCallback(lambda res: ms(mode=MODE_READ)) # this more stops at k+epsilon, and epsilon=k, so 6 shares d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 6)) d.addCallback(lambda res: ms(mode=MODE_ANYTHING)) @@ -455,7 +455,7 @@ class Servermap(unittest.TestCase): # increasing order of number of servers queried, since once a server # gets into the servermap, we'll always ask it for an update. d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 3)) - d.addCallback(lambda sm: us(sm, mode=MODE_ENOUGH)) + d.addCallback(lambda sm: us(sm, mode=MODE_READ)) d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 6)) d.addCallback(lambda sm: us(sm, mode=MODE_WRITE)) d.addCallback(lambda sm: us(sm, mode=MODE_CHECK)) @@ -470,7 +470,7 @@ class Servermap(unittest.TestCase): ms = self.make_servermap us = self.update_servermap - d.addCallback(lambda res: ms(mode=MODE_ENOUGH)) + d.addCallback(lambda res: ms(mode=MODE_READ)) d.addCallback(lambda sm: self.failUnlessOneRecoverable(sm, 6)) def _made_map(sm): v = sm.best_recoverable_version() @@ -521,7 +521,7 @@ class Servermap(unittest.TestCase): d.addCallback(lambda res: ms(mode=MODE_WRITE)) d.addCallback(lambda sm: self.failUnlessNoneRecoverable(sm)) - d.addCallback(lambda res: ms(mode=MODE_ENOUGH)) + d.addCallback(lambda res: ms(mode=MODE_READ)) d.addCallback(lambda sm: self.failUnlessNoneRecoverable(sm)) return d @@ -554,7 +554,7 @@ class Servermap(unittest.TestCase): d.addCallback(lambda sm: self.failUnlessNotQuiteEnough(sm)) d.addCallback(lambda res: ms(mode=MODE_WRITE)) d.addCallback(lambda sm: self.failUnlessNotQuiteEnough(sm)) - d.addCallback(lambda res: ms(mode=MODE_ENOUGH)) + d.addCallback(lambda res: ms(mode=MODE_READ)) d.addCallback(lambda sm: self.failUnlessNotQuiteEnough(sm)) return d @@ -575,7 +575,7 @@ class Roundtrip(unittest.TestCase): d.addCallback(_created) return d - def make_servermap(self, mode=MODE_ENOUGH, oldmap=None): + def make_servermap(self, mode=MODE_READ, oldmap=None): if oldmap is None: oldmap = ServerMap() smu = ServermapUpdater(self._fn, oldmap, mode) @@ -784,7 +784,7 @@ class Roundtrip(unittest.TestCase): def test_corrupt_some(self): # corrupt the data of first five shares (so the servermap thinks # they're good but retrieve marks them as bad), so that the - # MODE_ENOUGH set of 6 will be insufficient, forcing node.download to + # MODE_READ set of 6 will be insufficient, forcing node.download to # retry with more servers. corrupt(None, self._storage, "share_data", range(5)) d = self.make_servermap() @@ -847,7 +847,7 @@ class MultipleEncodings(unittest.TestCase): d.addCallback(_published) return d - def make_servermap(self, mode=MODE_ENOUGH, oldmap=None): + def make_servermap(self, mode=MODE_READ, oldmap=None): if oldmap is None: oldmap = ServerMap() smu = ServermapUpdater(self._fn, oldmap, mode)