From: Brian Warner Date: Tue, 15 Jan 2008 04:19:20 +0000 (-0700) Subject: upload: improve logging X-Git-Url: https://git.rkrishnan.org/pf/content//%22file:/%22?a=commitdiff_plain;h=60090fb9f2feabc65bb123d3cdbe088a37f78a7f;p=tahoe-lafs%2Ftahoe-lafs.git upload: improve logging --- diff --git a/src/allmydata/encode.py b/src/allmydata/encode.py index 3f51fae1..2467aaf6 100644 --- a/src/allmydata/encode.py +++ b/src/allmydata/encode.py @@ -5,7 +5,7 @@ from twisted.internet import defer from foolscap import eventual from allmydata import uri from allmydata.hashtree import HashTree -from allmydata.util import mathutil, hashutil, idlib +from allmydata.util import mathutil, hashutil, idlib, log from allmydata.util.assertutil import _assert from allmydata.codec import CRSEncoder from allmydata.interfaces import IEncoder, IStorageBucketWriter, \ @@ -89,19 +89,19 @@ class Encoder(object): self._codec = None self._parent = parent if self._parent: - self._log_number = self._parent.log("starting Encoder %s" % self) + self._log_number = self._parent.log("creating Encoder %s" % self) def __repr__(self): if hasattr(self, "_storage_index"): return "" % idlib.b2a(self._storage_index)[:6] return "" - def log(self, msg, parent=None): + def log(self, *args, **kwargs): if not self._parent: return - if parent is None: - parent = self._log_number - return self._parent.log(msg, parent=parent) + if "parent" not in kwargs: + kwargs["parent"] = self._log_number + return self._parent.log(*args, **kwargs) def set_size(self, size): assert not self._codec @@ -214,7 +214,8 @@ class Encoder(object): self.landlords = landlords.copy() def start(self): - self.log("starting") + if self._parent: + self._log_number = self._parent.log("%s starting" % (self,)) #paddedsize = self._size + mathutil.pad_size(self._size, self.needed_shares) if not self._codec: self._setup_codec() @@ -413,10 +414,10 @@ class Encoder(object): return defer.succeed(None) sh = self.landlords[shareid] lognum2 = self.log("put_block to %s" % self.landlords[shareid], - parent=lognum) + parent=lognum, level=log.NOISY) d = sh.put_block(segment_num, subshare) def _done(res): - self.log("put_block done", parent=lognum2) + self.log("put_block done", parent=lognum2, level=log.NOISY) return res d.addCallback(_done) d.addErrback(self._remove_shareholder, shareid, diff --git a/src/allmydata/upload.py b/src/allmydata/upload.py index a0ef6af7..3036d04b 100644 --- a/src/allmydata/upload.py +++ b/src/allmydata/upload.py @@ -105,12 +105,13 @@ class PeerTracker: class Tahoe2PeerSelector: - def __init__(self, upload_id): + def __init__(self, upload_id, logparent=None): self.upload_id = upload_id self.query_count, self.good_query_count, self.bad_query_count = 0,0,0 self.error_count = 0 self.num_peers_contacted = 0 self.last_failure_msg = None + self._log_parent = log.msg("%s starting" % self, parent=logparent) def __repr__(self): return "" % self.upload_id @@ -131,6 +132,7 @@ class Tahoe2PeerSelector: # self.uncontacted_peers = list() # peers we haven't asked yet self.contacted_peers = [] # peers worth asking again self.contacted_peers2 = [] # peers that we have asked again + self._started_second_pass = False self.use_peers = set() # PeerTrackers that have shares assigned to them self.preexisting_shares = {} # sharenum -> PeerTracker holding the share @@ -183,7 +185,8 @@ class Tahoe2PeerSelector: self.query_count, self.num_peers_contacted, self.good_query_count, self.bad_query_count, self.error_count)) - log.msg("peer selection successful for %s: %s" % (self, msg)) + log.msg("peer selection successful for %s: %s" % (self, msg), + parent=self._log_parent) return self.use_peers if self.uncontacted_peers: @@ -200,6 +203,10 @@ class Tahoe2PeerSelector: return d elif self.contacted_peers: # ask a peer that we've already asked. + if not self._started_second_pass: + log.msg("starting second pass", parent=self._log_parent, + level=log.NOISY) + self._started_second_pass = True num_shares = mathutil.div_ceil(len(self.homeless_shares), len(self.contacted_peers)) peer = self.contacted_peers.pop(0) @@ -232,7 +239,7 @@ class Tahoe2PeerSelector: msg = "peer selection failed for %s: %s" % (self, msg) if self.last_failure_msg: msg += " (%s)" % (self.last_failure_msg,) - log.msg(msg) + log.msg(msg, level=log.UNUSUAL, parent=self._log_parent) raise encode.NotEnoughPeersError(msg) else: # we placed enough to be happy, so we're done @@ -242,7 +249,8 @@ class Tahoe2PeerSelector: if isinstance(res, failure.Failure): # This is unusual, and probably indicates a bug or a network # problem. - log.msg("%s got error during peer selection: %s" % (peer, res)) + log.msg("%s got error during peer selection: %s" % (peer, res), + level=log.UNUSUAL, parent=self._log_parent) self.error_count += 1 self.homeless_shares = list(shares_to_ask) + self.homeless_shares if (self.uncontacted_peers @@ -260,6 +268,10 @@ class Tahoe2PeerSelector: self.last_failure_msg = msg else: (alreadygot, allocated) = res + log.msg("response from peer %s: alreadygot=%s, allocated=%s" + % (idlib.shortnodeid_b2a(peer.peerid), + tuple(sorted(alreadygot)), tuple(sorted(allocated))), + level=log.NOISY, parent=self._log_parent) progress = False for s in alreadygot: self.preexisting_shares[s] = peer @@ -428,10 +440,12 @@ class CHKUploader: def set_params(self, encoding_parameters): self._encoding_parameters = encoding_parameters - def log(self, msg, parent=None, **kwargs): - if parent is None: - parent = self._log_number - return self._client.log(msg, parent=parent, **kwargs) + def log(self, *args, **kwargs): + if "parent" not in kwargs: + kwargs["parent"] = self._log_number + if "facility" not in kwargs: + kwargs["facility"] = "tahoe.upload" + return self._client.log(*args, **kwargs) def start(self, uploadable): """Start uploading the file. @@ -467,7 +481,7 @@ class CHKUploader: storage_index = encoder.get_param("storage_index") upload_id = idlib.b2a(storage_index)[:6] self.log("using storage index %s" % upload_id) - peer_selector = self.peer_selector_class(upload_id) + peer_selector = self.peer_selector_class(upload_id, self._log_number) share_size = encoder.get_param("share_size") block_size = encoder.get_param("block_size")