From ae5b4980f2a4403bfd22097c2c9a93b5169061bc Mon Sep 17 00:00:00 2001 From: Marian Beermann Date: Thu, 15 Sep 2016 11:23:58 +0200 Subject: [PATCH 1/3] Repository.check: improve object count mismatch diagnostic --- src/borg/repository.py | 18 +++++++++++++++++- 1 file changed, 17 insertions(+), 1 deletion(-) diff --git a/src/borg/repository.py b/src/borg/repository.py index 6c0159a72..022a8d48b 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -687,7 +687,23 @@ class Repository: # current_index = "as found on disk" # self.index = "as rebuilt in-memory from segments" if len(current_index) != len(self.index): - report_error('Index object count mismatch. {} != {}'.format(len(current_index), len(self.index))) + report_error('Index object count mismatch.') + logger.error('committed index: %d objects', len(current_index)) + logger.error('rebuilt index: %d objects', len(self.index)) + + line_format = '%-64s %-16s %-16s' + not_found = '' + logger.warning(line_format, 'ID', 'rebuilt index', 'committed index') + for key, value in self.index.iteritems(): + current_value = current_index.get(key, not_found) + if current_value != value: + logger.warning(line_format, bin_to_hex(key), value, current_value) + for key, current_value in current_index.iteritems(): + if key in self.index: + continue + value = self.index.get(key, not_found) + if current_value != value: + logger.warning(line_format, bin_to_hex(key), value, current_value) elif current_index: for key, value in self.index.iteritems(): if current_index.get(key, (-1, -1)) != value: From abace16945b9336b3ea7be43f23d98c1bbbe876b Mon Sep 17 00:00:00 2001 From: Marian Beermann Date: Sun, 25 Sep 2016 10:12:42 +0200 Subject: [PATCH 2/3] Repository.check: log transaction IDs --- src/borg/repository.py | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/src/borg/repository.py b/src/borg/repository.py index 022a8d48b..c4e27f726 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -650,18 +650,25 @@ class Repository: try: transaction_id = self.get_transaction_id() current_index = self.open_index(transaction_id) - except Exception: + logger.debug('Read committed index of transaction %d', transaction_id) + except Exception as exc: transaction_id = self.io.get_segments_transaction_id() current_index = None + logger.debug('Failed to read committed index (%s)', exc) if transaction_id is None: + logger.debug('No segments transaction found') transaction_id = self.get_index_transaction_id() if transaction_id is None: + logger.debug('No index transaction found, trying latest segment') transaction_id = self.io.get_latest_segment() if repair: self.io.cleanup(transaction_id) segments_transaction_id = self.io.get_segments_transaction_id() + logger.debug('Segment transaction is %s', segments_transaction_id) + logger.debug('Determined transaction is %s', transaction_id) self.prepare_txn(None) # self.index, self.compact, self.segments all empty now! segment_count = sum(1 for _ in self.io.segment_iterator()) + logger.debug('Found %d segments', segment_count) pi = ProgressIndicatorPercent(total=segment_count, msg="Checking segments %3.1f%%", step=0.1) for i, (segment, filename) in enumerate(self.io.segment_iterator()): pi.show(i) @@ -683,6 +690,7 @@ class Repository: report_error('Adding commit tag to segment {}'.format(transaction_id)) self.io.segment = transaction_id + 1 self.io.write_commit() + logger.info('Starting repository index check') if current_index and not repair: # current_index = "as found on disk" # self.index = "as rebuilt in-memory from segments" From 7b1f10347a766b87deabfac96d5e6d0cc9b2aa39 Mon Sep 17 00:00:00 2001 From: Marian Beermann Date: Sat, 17 Sep 2016 16:39:55 +0200 Subject: [PATCH 3/3] Repository: compact: fix incorrect preservation of delete tags --- src/borg/repository.py | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/src/borg/repository.py b/src/borg/repository.py index c4e27f726..fa197ebfa 100644 --- a/src/borg/repository.py +++ b/src/borg/repository.py @@ -481,8 +481,9 @@ class Repository: for tag, key, offset, data in self.io.iter_objects(segment, include_data=True): if tag == TAG_COMMIT: continue - in_index = self.index.get(key) == (segment, offset) - if tag == TAG_PUT and in_index: + in_index = self.index.get(key) + is_index_object = in_index == (segment, offset) + if tag == TAG_PUT and is_index_object: try: new_segment, offset = self.io.write_put(key, data, raise_full=True) except LoggedIO.SegmentFull: @@ -492,22 +493,23 @@ class Repository: segments.setdefault(new_segment, 0) segments[new_segment] += 1 segments[segment] -= 1 - elif tag == TAG_PUT and not in_index: + elif tag == TAG_PUT and not is_index_object: # If this is a PUT shadowed by a later tag, then it will be gone when this segment is deleted after # this loop. Therefore it is removed from the shadow index. try: self.shadow_index[key].remove(segment) except (KeyError, ValueError): pass - elif tag == TAG_DELETE: + elif tag == TAG_DELETE and not in_index: # If the shadow index doesn't contain this key, then we can't say if there's a shadowed older tag, # therefore we do not drop the delete, but write it to a current segment. shadowed_put_exists = key not in self.shadow_index or any( # If the key is in the shadow index and there is any segment with an older PUT of this # key, we have a shadowed put. shadowed < segment for shadowed in self.shadow_index[key]) + delete_is_not_stable = index_transaction_id is None or segment > index_transaction_id - if shadowed_put_exists or index_transaction_id is None or segment > index_transaction_id: + if shadowed_put_exists or delete_is_not_stable: # (introduced in 6425d16aa84be1eaaf88) # This is needed to avoid object un-deletion if we crash between the commit and the deletion # of old segments in complete_xfer().