mirror of
https://github.com/tahoe-lafs/tahoe-lafs.git
synced 2025-01-04 12:14:11 +00:00
mutable.py: log more information during publish, specifically the sharemap, and the reason for an UncoordinatedWriteError
This commit is contained in:
parent
0af1a9e1c5
commit
689c71f946
@ -716,16 +716,16 @@ class Publish:
|
|||||||
num = self._node._client.log("Publish(%s): starting" % prefix)
|
num = self._node._client.log("Publish(%s): starting" % prefix)
|
||||||
self._log_number = num
|
self._log_number = num
|
||||||
|
|
||||||
def log(self, msg, parent=None, **kwargs):
|
def log(self, *args, **kwargs):
|
||||||
prefix = self._log_prefix
|
if 'parent' not in kwargs:
|
||||||
if parent is None:
|
kwargs['parent'] = self._log_number
|
||||||
parent = self._log_number
|
num = log.msg(*args, **kwargs)
|
||||||
num = self._node._client.log("Publish(%s): %s" % (prefix, msg),
|
|
||||||
parent=parent, **kwargs)
|
|
||||||
return num
|
return num
|
||||||
|
|
||||||
def log_err(self, f):
|
def log_err(self, *args, **kwargs):
|
||||||
num = log.err(f, parent=self._log_number)
|
if 'parent' not in kwargs:
|
||||||
|
kwargs['parent'] = self._log_number
|
||||||
|
num = log.err(*args, **kwargs)
|
||||||
return num
|
return num
|
||||||
|
|
||||||
def publish(self, newdata, wait_for_numpeers=None):
|
def publish(self, newdata, wait_for_numpeers=None):
|
||||||
@ -881,14 +881,14 @@ class Publish:
|
|||||||
def _got_query_results(self, datavs, peerid, permutedid,
|
def _got_query_results(self, datavs, peerid, permutedid,
|
||||||
reachable_peers, current_share_peers):
|
reachable_peers, current_share_peers):
|
||||||
|
|
||||||
lp = self.log("_got_query_results from %s" %
|
lp = self.log(format="_got_query_results from %(peerid)s",
|
||||||
idlib.shortnodeid_b2a(peerid))
|
peerid=idlib.shortnodeid_b2a(peerid))
|
||||||
assert isinstance(datavs, dict)
|
assert isinstance(datavs, dict)
|
||||||
reachable_peers[peerid] = permutedid
|
reachable_peers[peerid] = permutedid
|
||||||
if not datavs:
|
if not datavs:
|
||||||
self.log("peer has no shares", parent=lp)
|
self.log("peer has no shares", parent=lp)
|
||||||
for shnum, datav in datavs.items():
|
for shnum, datav in datavs.items():
|
||||||
self.log("peer has shnum %d" % shnum, parent=lp)
|
lp2 = self.log("peer has shnum %d" % shnum, parent=lp)
|
||||||
assert len(datav) == 1
|
assert len(datav) == 1
|
||||||
data = datav[0]
|
data = datav[0]
|
||||||
# We want (seqnum, root_hash, IV) from all servers to know what
|
# We want (seqnum, root_hash, IV) from all servers to know what
|
||||||
@ -907,10 +907,13 @@ class Publish:
|
|||||||
# self._pubkey is present because we require read-before-replace
|
# self._pubkey is present because we require read-before-replace
|
||||||
valid = self._pubkey.verify(prefix, signature)
|
valid = self._pubkey.verify(prefix, signature)
|
||||||
if not valid:
|
if not valid:
|
||||||
self.log("bad signature from %s shnum %d" %
|
self.log(format="bad signature from %(peerid)s shnum %(shnum)d",
|
||||||
(shnum, idlib.shortnodeid_b2a(peerid)),
|
peerid=idlib.shortnodeid_b2a(peerid), shnum=shnum,
|
||||||
parent=lp, level=log.WEIRD)
|
parent=lp2, level=log.WEIRD)
|
||||||
continue
|
continue
|
||||||
|
self.log(format="peer has goodsig shnum %(shnum)d seqnum %(seqnum)d",
|
||||||
|
shnum=shnum, seqnum=seqnum,
|
||||||
|
parent=lp2, level=log.NOISY)
|
||||||
|
|
||||||
share = (shnum, seqnum, root_hash)
|
share = (shnum, seqnum, root_hash)
|
||||||
current_share_peers.add(shnum, (peerid, seqnum, root_hash) )
|
current_share_peers.add(shnum, (peerid, seqnum, root_hash) )
|
||||||
@ -978,6 +981,19 @@ class Publish:
|
|||||||
# TODO: 2: move those shares instead of copying them, to reduce future
|
# TODO: 2: move those shares instead of copying them, to reduce future
|
||||||
# update work
|
# update work
|
||||||
|
|
||||||
|
# if log.recording_noisy
|
||||||
|
logmsg = []
|
||||||
|
for shnum in range(total_shares):
|
||||||
|
logmsg2 = []
|
||||||
|
for oldplace in current_share_peers.get(shnum, []):
|
||||||
|
(peerid, seqnum, R) = oldplace
|
||||||
|
logmsg2.append("%s:#%d:R=%s" % (idlib.shortnodeid_b2a(peerid),
|
||||||
|
seqnum, idlib.b2a(R)[:4]))
|
||||||
|
logmsg.append("sh%d on (%s)" % (shnum, "/".join(logmsg2)))
|
||||||
|
self.log("sharemap: %s" % (", ".join(logmsg)), level=log.NOISY)
|
||||||
|
self.log("we are planning to push new seqnum=#%d" % self._new_seqnum,
|
||||||
|
level=log.NOISY)
|
||||||
|
|
||||||
shares_needing_homes = range(total_shares)
|
shares_needing_homes = range(total_shares)
|
||||||
target_map = DictOfSets() # maps shnum to set((peerid,oldseqnum,oldR))
|
target_map = DictOfSets() # maps shnum to set((peerid,oldseqnum,oldR))
|
||||||
shares_per_peer = DictOfSets()
|
shares_per_peer = DictOfSets()
|
||||||
@ -985,7 +1001,13 @@ class Publish:
|
|||||||
for oldplace in current_share_peers.get(shnum, []):
|
for oldplace in current_share_peers.get(shnum, []):
|
||||||
(peerid, seqnum, R) = oldplace
|
(peerid, seqnum, R) = oldplace
|
||||||
if seqnum >= self._new_seqnum:
|
if seqnum >= self._new_seqnum:
|
||||||
raise UncoordinatedWriteError()
|
self.log("somebody has a newer sequence number than what we were uploading",
|
||||||
|
level=log.WEIRD)
|
||||||
|
self.log(format="peerid=%(peerid)s, theirs=%(seqnum)d, mine=%(new_seqnum)d",
|
||||||
|
peerid=idlib.shortnodeid_b2a(peerid),
|
||||||
|
seqnum=seqnum,
|
||||||
|
new_seqnum=self._new_seqnum)
|
||||||
|
raise UncoordinatedWriteError("somebody has a newer sequence number than us")
|
||||||
target_map.add(shnum, oldplace)
|
target_map.add(shnum, oldplace)
|
||||||
shares_per_peer.add(peerid, shnum)
|
shares_per_peer.add(peerid, shnum)
|
||||||
if shnum in shares_needing_homes:
|
if shnum in shares_needing_homes:
|
||||||
@ -1224,7 +1246,8 @@ class Publish:
|
|||||||
def _got_write_answer(self, answer, tw_vectors, my_checkstring,
|
def _got_write_answer(self, answer, tw_vectors, my_checkstring,
|
||||||
peerid, expected_old_shares,
|
peerid, expected_old_shares,
|
||||||
dispatch_map):
|
dispatch_map):
|
||||||
self.log("_got_write_answer from %s" % idlib.shortnodeid_b2a(peerid))
|
lp = self.log("_got_write_answer from %s" %
|
||||||
|
idlib.shortnodeid_b2a(peerid))
|
||||||
wrote, read_data = answer
|
wrote, read_data = answer
|
||||||
surprised = False
|
surprised = False
|
||||||
|
|
||||||
@ -1235,6 +1258,8 @@ class Publish:
|
|||||||
dispatch_map.add(shnum, (peerid, new_seqnum, new_root_hash))
|
dispatch_map.add(shnum, (peerid, new_seqnum, new_root_hash))
|
||||||
else:
|
else:
|
||||||
# surprise! our testv failed, so the write did not happen
|
# surprise! our testv failed, so the write did not happen
|
||||||
|
self.log("our testv failed, that write did not happen",
|
||||||
|
parent=lp, level=log.WEIRD)
|
||||||
surprised = True
|
surprised = True
|
||||||
|
|
||||||
for shnum, (old_cs,) in read_data.items():
|
for shnum, (old_cs,) in read_data.items():
|
||||||
@ -1245,12 +1270,21 @@ class Publish:
|
|||||||
|
|
||||||
if shnum not in expected_old_shares:
|
if shnum not in expected_old_shares:
|
||||||
# surprise! there was a share we didn't know about
|
# surprise! there was a share we didn't know about
|
||||||
|
self.log("they had share %d that we didn't know about" % shnum,
|
||||||
|
parent=lp, level=log.WEIRD)
|
||||||
surprised = True
|
surprised = True
|
||||||
else:
|
else:
|
||||||
seqnum, root_hash = expected_old_shares[shnum]
|
seqnum, root_hash = expected_old_shares[shnum]
|
||||||
if seqnum is not None:
|
if seqnum is not None:
|
||||||
if seqnum != old_seqnum or root_hash != old_root_hash:
|
if seqnum != old_seqnum or root_hash != old_root_hash:
|
||||||
# surprise! somebody modified the share on us
|
# surprise! somebody modified the share on us
|
||||||
|
self.log("somebody modified the share on us:"
|
||||||
|
" shnum=%d: I thought they had #%d:R=%s,"
|
||||||
|
" but testv reported #%d:R=%s" %
|
||||||
|
(shnum,
|
||||||
|
seqnum, idlib.b2a(root_hash)[:4],
|
||||||
|
old_seqnum, idlib.b2a(old_root_hash)[:4]),
|
||||||
|
parent=lp, level=log.WEIRD)
|
||||||
surprised = True
|
surprised = True
|
||||||
if surprised:
|
if surprised:
|
||||||
self._surprised = True
|
self._surprised = True
|
||||||
@ -1261,14 +1295,17 @@ class Publish:
|
|||||||
seqnum,
|
seqnum,
|
||||||
idlib.b2a(root_hash)[:4])
|
idlib.b2a(root_hash)[:4])
|
||||||
for (peerid,seqnum,root_hash) in places]
|
for (peerid,seqnum,root_hash) in places]
|
||||||
self.log(" share %d sent to: %s" % (shnum, sent_to))
|
self.log(" share %d sent to: %s" % (shnum, sent_to),
|
||||||
|
level=log.NOISY)
|
||||||
|
|
||||||
def _maybe_recover(self, (surprised, dispatch_map)):
|
def _maybe_recover(self, (surprised, dispatch_map)):
|
||||||
self.log("_maybe_recover, surprised=%s, dispatch_map:" % surprised)
|
self.log("_maybe_recover, surprised=%s, dispatch_map:" % surprised,
|
||||||
|
level=log.NOISY)
|
||||||
self._log_dispatch_map(dispatch_map)
|
self._log_dispatch_map(dispatch_map)
|
||||||
if not surprised:
|
if not surprised:
|
||||||
self.log(" no recovery needed")
|
self.log(" no recovery needed")
|
||||||
return
|
return
|
||||||
|
self.log("We need recovery!", level=log.WEIRD)
|
||||||
print "RECOVERY NOT YET IMPLEMENTED"
|
print "RECOVERY NOT YET IMPLEMENTED"
|
||||||
# but dispatch_map will help us do it
|
# but dispatch_map will help us do it
|
||||||
raise UncoordinatedWriteError("I was surprised!")
|
raise UncoordinatedWriteError("I was surprised!")
|
||||||
|
Loading…
Reference in New Issue
Block a user