check: survive I/O errors while reading repository objects

docs/changes.rst

@@ -187,6 +187,13 @@ Fixes:
 
   - do not report a merely touched file as modified when the chunker params differ, #10351
   - report a file as modified when chunks were reordered or duplicated
+- check: do not crash with a traceback when a repository object can not be read
+  (I/O error, e.g. failing disk or flaky network filesystem). The affected object
+  is reported, the check continues and fails at the end. Such an object is not
+  recorded as corrupt (a later check verifies it again), ``--repair`` refuses to
+  repair around it and ``--verify-data`` no longer deletes chunks it could not
+  read. Other commands stop with the read error instead of working with a
+  partially readable repository, #3509
 
 Other changes:
 

docs/internals/frontends.rst

@@ -855,6 +855,10 @@ Errors
         Object with key {} is indexed to pack {}, but that whole pack is missing from repository {}.
     Repository.PermissionDenied rc: 24 traceback: no
         Repository permission denied: {}
+    Repository.RepairUnsafe rc: 29 traceback: no
+        Not repairing: {} repository object(s) could not be read. Fix the underlying problem, then check again.
+    Repository.StoreReadError rc: 28 traceback: no
+        Error reading {} from the repository: {}. Check the storage hardware / filesystem.
 
     MandatoryFeatureUnsupported rc: 25 traceback: no
         Unsupported repository feature(s) {}. A newer version of Borg is required to access this repository.

docs/usage/check.rst.inc

@@ -98,12 +98,12 @@ The check command verifies the consistency of a repository and its archives.
 It consists of two major steps:
 
 1. Checking the consistency of the repository itself. The objects in the ``index/``
-   and ``packs/`` namespaces are named by the sha256 hash of their content, so such
+   and ``packs/`` namespaces are named by the store hash of their content, so such
    an object is intact if and only if the hash of its content still equals its name.
    The check verifies the (small) index objects first and, only if they are intact,
    all packs. It also cross-checks the chunk index against the packs present in the
    repository to detect referenced but missing packs. Bit rot and other types of
-   accidental damage can be detected this way, but as sha256 content-addressing is
+   accidental damage can be detected this way, but as content-addressing is
    not a MAC, this step does not detect tampering. Running the repository check can
    be split into multiple partial checks using ``--max-duration``.
    For rest:// repositories, the server computes the hashes, so the pack contents do
@@ -199,6 +199,24 @@ packs, and, if the key must be recovered, scans chunks for it. These phases do n
 respond to SIGINT, so on a large repository a Ctrl-C during them may appear to have no
 effect until they finish.
 
+Unreadable repository objects
++++++++++++++++++++++++++++++
+
+A repository object that cannot be read at all (an I/O error from a failing disk, a
+flaky network filesystem, ...) is different from a corrupt one: Borg never saw its
+content, so it cannot tell whether the object is fine. Such an object is reported and
+the check continues, so one run lists everything that is affected; the check then
+fails. The object is not remembered as corrupt, so a later check verifies it again.
+
+Because the data may well be readable again once the underlying problem is fixed,
+``--repair`` refuses to repair while there are unreadable objects, and
+``--verify-data`` leaves chunks it could not read in place instead of deleting them.
+Fix the storage hardware, filesystem or network first, then run the check again.
+
+Only ``borg check`` goes on like this. Other commands stop with the read error rather
+than work with a partially readable repository - e.g. ``borg prune`` would otherwise
+see an archive whose metadata it could not read as undated and thus as the oldest one.
+
 About repair mode
 +++++++++++++++++
 

src/borg/archive.py

@@ -2375,6 +2375,7 @@ def verify_data(self):
         errors = 0
         verified = 0  # chunks actually verified
         defect_chunks = []
+        unreadable_chunks = 0  # chunks we could not even read, refs #3509
         pi = ProgressIndicatorPercent(
             total=chunks_count, msg="Verifying data %6.2f%%", step=0.01, msgid="check.verify_data"
         )
@@ -2385,6 +2386,13 @@ def verify_data(self):
             verified += 1
             try:
                 encrypted_data = self.repository.get(chunk_id)
+            except Repository.StoreReadError as err:
+                # unreadable, not defect: we did not see the content, so we must not conclude it is
+                # bad and delete it - it may read fine once the hardware/fs problem is fixed, refs #3509.
+                self.error_found = True
+                errors += 1
+                unreadable_chunks += 1
+                logger.error("chunk %s: %s", bin_to_hex(chunk_id), err)
             except (Repository.ObjectNotFound, IntegrityErrorBase) as err:
                 self.error_found = True
                 errors += 1
@@ -2425,6 +2433,11 @@ def verify_data(self):
                             ro_type=ROBJ_DONTCARE,
                             assert_id_place="verify_data",
                         )
+                    except Repository.StoreReadError as err:
+                        # the retry did not fail on the content, it failed to read at all: keep the
+                        # chunk, the read may well succeed again later, refs #3509.
+                        unreadable_chunks += 1
+                        logger.error("chunk %s not deleted, could not be re-read: %s", bin_to_hex(defect_chunk), err)
                     except IntegrityErrorBase:
                         # failed twice -> remove this defect chunk. delete rewrites its pack without it,
                         # keeping the other chunks. update_index=False: finish() rebuilds the index from
@@ -2439,18 +2452,23 @@ def verify_data(self):
                 logger.warning("Found defect chunks. Run with --repair to remove them.")
                 for defect_chunk in defect_chunks:
                     logger.debug("chunk %s is defect.", bin_to_hex(defect_chunk))
+        if unreadable_chunks:
+            logger.error(
+                "%d chunk(s) could not be read and were left untouched. This usually means a hardware, "
+                "filesystem or network problem - fix that first, then run the check again.",
+                unreadable_chunks,
+            )
         log = logger.error if errors else logger.info
         if sig_int:
             log(
-                "Interrupted cryptographic data integrity verification, "
-                "verified %d of %d chunks with %d integrity errors.",
+                "Interrupted cryptographic data integrity verification, verified %d of %d chunks with %d error(s).",
                 verified,
                 chunks_count,
                 errors,
             )
         else:
             log(
-                "Finished cryptographic data integrity verification, verified %d chunks with %d integrity errors.",
+                "Finished cryptographic data integrity verification, verified %d chunks with %d error(s).",
                 verified,
                 errors,
             )
@@ -2487,23 +2505,33 @@ def valid_archive(obj):
             if sig_int:
                 break
             pi.show()
-            cdata = self.repository.get(chunk_id, read_data=False)  # only get metadata
             try:
+                cdata = self.repository.get(chunk_id, read_data=False)  # only get metadata
                 meta = self.repo_objs.parse_meta(chunk_id, cdata, ro_type=ROBJ_DONTCARE)
             except IntegrityErrorBase as exc:
                 logger.error("Skipping corrupted chunk: %s", exc)
                 self.error_found = True
                 continue
+            except Repository.StoreReadError as exc:
+                # unreadable, not corrupt: this scan only looks for archive metadata, so skipping
+                # such a chunk can at worst miss a lost archive - it never drops data, refs #3509.
+                logger.error("Skipping unreadable chunk: %s", exc)
+                self.error_found = True
+                continue
             if meta["type"] != ROBJ_ARCHIVE_META:
                 continue
             # now we know it is an archive metadata chunk, load the full object from the repo:
-            cdata = self.repository.get(chunk_id)
             try:
+                cdata = self.repository.get(chunk_id)
                 meta, data = self.repo_objs.parse(chunk_id, cdata, ro_type=ROBJ_DONTCARE)
             except IntegrityErrorBase as exc:
                 logger.error("Skipping corrupted chunk: %s", exc)
                 self.error_found = True
                 continue
+            except Repository.StoreReadError as exc:
+                logger.error("Skipping unreadable chunk: %s", exc)
+                self.error_found = True
+                continue
             if meta["type"] != ROBJ_ARCHIVE_META:
                 continue  # should never happen
             try:
@@ -2717,6 +2745,9 @@ def valid_item(obj):
                 newest=newest,
                 older=older,
                 newer=newer,
+                # an archive whose metadata we can not read gets a placeholder entry here, so the
+                # other archives still get checked; the loop below reports it, refs #3509.
+                tolerate_read_errors=True,
             )
             if match and not archive_infos:
                 logger.warning("--match-archives %s does not match any archives", match)
@@ -2725,7 +2756,7 @@ def valid_item(obj):
             if last and len(archive_infos) < last:
                 logger.warning("--last %d archives: only found %d archives", last, len(archive_infos))
         else:
-            archive_infos = self.manifest.archives.list(sort_by=sort_by)
+            archive_infos = self.manifest.archives.list(sort_by=sort_by, tolerate_read_errors=True)
         num_archives = len(archive_infos)
         formatter = ArchiveFormatter(self.format, self.repository, self.manifest, self.key)
 
@@ -2744,9 +2775,10 @@ def valid_item(obj):
                 archive_id, archive_id_hex = info.id, bin_to_hex(info.id)
                 try:
                     formatted = formatter.format_item(info, jsonline=False)
-                except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase):
-                    # keys like {comment} need the archive metadata, which is damaged or missing here.
-                    # use the values from the archive directory entry, they are always available.
+                except (Archive.DoesNotExist, Repository.ObjectNotFound, IntegrityErrorBase, Repository.StoreReadError):
+                    # keys like {comment} need the archive metadata, which is damaged, missing or
+                    # unreadable here. use the values from the archive directory entry, they are
+                    # always available.
                     formatted = f"{info.name} {OutputTimestamp(info.ts)} {archive_id_hex}"
                 logger.info(f"Analyzing archive {formatted} ({i + 1}/{num_archives})")
                 if archive_id not in self.chunks:
@@ -2758,9 +2790,17 @@ def valid_item(obj):
                     else:
                         logger.error(f"Would delete broken archive {info.name} {archive_id_hex}.")
                     continue
-                cdata = self.repository.get(archive_id)
                 try:
+                    cdata = self.repository.get(archive_id)
                     _, data = self.repo_objs.parse(archive_id, cdata, ro_type=ROBJ_ARCHIVE_META)
+                except Repository.StoreReadError as err:
+                    # unreadable, not corrupt: we did not see the metadata, so we can not tell
+                    # whether this archive is fine - and must not "repair" it away, refs #3509.
+                    logger.error(f"Archive metadata block {archive_id_hex} could not be read: {err}")
+                    self.error_found = True
+                    if self.repair:
+                        raise
+                    continue
                 except IntegrityErrorBase as integrity_error:
                     logger.error(f"Archive metadata block {archive_id_hex} is corrupted: {integrity_error}")
                     self.error_found = True
@@ -2776,10 +2816,19 @@ def valid_item(obj):
                     raise Exception("Unknown archive metadata version")
                 items_buffer = ChunkBuffer(self.key)
                 items_buffer.write_chunk = add_callback
-                for item in robust_iterator(archive):
-                    if "chunks" in item:
-                        verify_file_chunks(info.name, item)
-                    items_buffer.add(item)
+                try:
+                    for item in robust_iterator(archive):
+                        if "chunks" in item:
+                            verify_file_chunks(info.name, item)
+                        items_buffer.add(item)
+                except Repository.StoreReadError as err:
+                    # part of the item metadata stream could not be read (see above): rewriting the
+                    # archive from what we did read would drop the rest of it, refs #3509.
+                    logger.error(f"Archive {info.name} {archive_id_hex} could not be read fully: {err}")
+                    self.error_found = True
+                    if self.repair:
+                        raise
+                    continue
                 items_buffer.flush(flush=True)
                 if self.repair:
                     archive.item_ptrs = archive_put_items(

src/borg/archiver/check_cmd.py

@@ -213,6 +213,24 @@ def build_parser_check(self, subparsers, common_parser, mid_common_parser):
         respond to SIGINT, so on a large repository a Ctrl-C during them may appear to have no
         effect until they finish.
 
+        Unreadable repository objects
+        +++++++++++++++++++++++++++++
+
+        A repository object that cannot be read at all (an I/O error from a failing disk, a
+        flaky network filesystem, ...) is different from a corrupt one: Borg never saw its
+        content, so it cannot tell whether the object is fine. Such an object is reported and
+        the check continues, so one run lists everything that is affected; the check then
+        fails. The object is not remembered as corrupt, so a later check verifies it again.
+
+        Because the data may well be readable again once the underlying problem is fixed,
+        ``--repair`` refuses to repair while there are unreadable objects, and
+        ``--verify-data`` leaves chunks it could not read in place instead of deleting them.
+        Fix the storage hardware, filesystem or network first, then run the check again.
+
+        Only ``borg check`` goes on like this. Other commands stop with the read error rather
+        than work with a partially readable repository - e.g. ``borg prune`` would otherwise
+        see an archive whose metadata it could not read as undated and thus as the oldest one.
+
         About repair mode
         +++++++++++++++++
 

src/borg/cache.py

@@ -936,12 +936,17 @@ def build_chunkindex_from_repo(
                 break
             chunks = ChunkIndex()  # we'll merge all fragments into this
             complete = True
-            corrupt_fragment = None
+            unusable_fragment = None  # message about a fragment that is corrupt or could not be read
             for hash in hashes:
                 try:
                     chunks_to_merge = read_chunkindex_from_repo(repository, hash)
                 except CorruptChunkIndexFragment as err:
-                    corrupt_fragment = err
+                    unusable_fragment = f"{err} is corrupt"
+                    break
+                except Repository.StoreReadError as err:
+                    # the fragment could not be read (I/O error, refs #3509). retrying would just hit
+                    # the same error, so give up on the fragments and rebuild from the packs instead.
+                    unusable_fragment = f"chunk index fragment {hash} could not be read: {err}"
                     break
                 if chunks_to_merge is None:
                     logger.debug(f"chunk index fragment {hash} vanished, restarting the merge...")
@@ -951,13 +956,13 @@ def build_chunkindex_from_repo(
                 for k, v in chunks_to_merge.items():
                     chunks[k] = v
                 chunks_to_merge.clear()
-            if corrupt_fragment is not None:
-                # retrying would re-read the same corrupt fragment; rebuild the whole index from
+            if unusable_fragment is not None:
+                # retrying would re-read the same unusable fragment; rebuild the whole index from
                 # the packs instead (or return None in fragments_only mode).
                 chunks.clear()
                 if fragments_only:
                     return None
-                logger.warning(f"{corrupt_fragment} is corrupt, rebuilding the chunk index from the packs.")
+                logger.warning(f"{unusable_fragment}, rebuilding the chunk index from the packs.")
                 break
             if complete:
                 if len(hashes) > 1 and write_immediately: