archive_progress: the final object has the final statistics

The progress output is rate limited and the final archive_progress object
(finished: true) had no statistics, so nothing reported what was processed
after the previous object, or anything at all for a short operation: a
transfer of 10000 files ended at "nfiles": 5653, a recreate of 500 files at 0.
create and import-tar have the final --json output for that, recreate and
transfer have nothing else.

The final object had lost its statistics because they were all 0 for create,
see #6570: create and import-tar reported the statistics of the archive before
adding the ones of the object processors to them. They add them first now.

The cockpit uses the statistics of the final object.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>

Author: ThomasWaldmann

docs/changes.rst

@@ -224,6 +224,9 @@ Fixes:
   documented), not text progress lines
 - import-tar/recreate: count the items by their status, like create does. The counts
   were always 0: "Added files" of import-tar --stats, files_stats in the JSON output.
+- --log-json: the final archive_progress object (finished: true) has the final statistics.
+  The progress output is rate limited, so a frontend could not know what was processed
+  after the previous object (or at all, for a short operation), see also #6570.
 
 Other changes:
 

docs/internals/frontends.rst

@@ -90,7 +90,8 @@ it is not produced unless ``--progress`` is specified.
 archive_progress
     Output during operations creating archives (:ref:`borg_create`, :ref:`borg_import-tar`,
     :ref:`borg_recreate` and :ref:`borg_transfer`).
-    The following keys exist, each represents the current progress.
+    The following keys exist, each represents the current progress. The output is rate limited, so
+    only the last object (*finished* is *true*) tells about everything that was processed.
 
     original_size
         Original size of the data processed so far (before compression and deduplication)
@@ -116,8 +117,8 @@ archive_progress
         Unix timestamp (float)
     finished
         boolean indicating whether the operation has finished, only the last object for an *operation*
-        can have this property set to *true*. That last object has no keys besides *time*, *type*
-        and *finished*.
+        can have this property set to *true*. That last object has the final statistics of the
+        archive and no *path*.
 
 progress_message
     A message-based progress information with no concrete progress information, just a message
@@ -241,7 +242,9 @@ See Prompts_ for the types used by prompts.
     {"type": "file_status", "status": "A", "path": "src/linux/file1"}
     {"type": "file_status", "status": "d", "path": "src/linux"}
     {"type": "file_status", "status": "d", "path": "src"}
-    {"time": 1787900398.686938, "type": "archive_progress", "finished": true}
+    {"original_size": 250012, "deduplicated_size": 250012, "nfiles": 3, "hashing_time": 0.002,
+     "chunking_time": 0.001, "files_stats": {"A": 3, "d": 3}, "store_stats": {}, "time": 1787900398.686938,
+     "type": "archive_progress", "finished": true}
 
 :ref:`borg_extract` file listing, with ``--exclude src/linux/baz/file3``::
 

src/borg/archive.py

@@ -208,12 +208,11 @@ def show_progress(self, item=None, final=False, stream=None):
             stream = stream or sys.stderr
             self.last_progress = now
             if self.output_json:
-                if not final:
-                    data = self.as_dict()
-                    if item:
-                        data |= text_to_json("path", item.path)
-                else:
-                    data = {}
+                # the progress is rate limited, so the final object must have the final statistics: nothing
+                # else reports what was processed since the previous object (or all of a short operation).
+                data = self.as_dict()
+                if item and not final:
+                    data |= text_to_json("path", item.path)
                 data |= {"time": time.time(), "type": "archive_progress", "finished": final}
                 msg = json.dumps(data)
                 end = "\n"

src/borg/archiver/create_cmd.py

@@ -291,9 +291,9 @@ def create_inner(archive, cache, fso):
                         self.print_warning_instance(BackupWarning(path, e))
                         continue
             if not dry_run:
+                archive.stats += fso.stats  # before the final progress, it reports the final statistics
                 if args.progress:
                     archive.stats.show_progress(final=True)
-                archive.stats += fso.stats
                 if sig_int:
                     # do not save the archive if the user ctrl-c-ed.
                     raise Error("Got Ctrl-C / SIGINT.")

src/borg/archiver/tar_cmds.py

@@ -614,9 +614,9 @@ def path_components(name):
         # This does not close the fileobj (tarstream) we passed to it -- a side effect of the | mode.
         tar.close()
 
+        archive.stats += tfo.stats  # before the final progress, it reports the final statistics
         if args.progress:
             archive.stats.show_progress(final=True)
-        archive.stats += tfo.stats
         archive.save(comment=args.comment, timestamp=args.timestamp)
         args.stats |= args.json
         if args.stats:

src/borg/cockpit/session.py

@@ -84,7 +84,7 @@ def __init__(self, command=None, capture_stdout=False):
         self.finished_at = None
         self.rc = None  # exit code of borg, None while it runs
         self.error = None  # why borg could not be run, if so
-        self.archive_progress = None  # the latest ArchiveProgress carrying statistics
+        self.archive_progress = None  # the latest ArchiveProgress
         self.archive_finished = False
         # status char -> count of the --list lines. They only tell about the listing (which --filter reduces),
         # the statistics of an archive being created never come from here, see nfiles and files_stats.
@@ -147,10 +147,9 @@ def _final_stat(self, key, types=int):
         value = stats.get(key) if stats else None
         return value if isinstance(value, types) and not isinstance(value, bool) else None
 
-    # The statistics come from borg's statistics only: the final ones (exact) are preferred over the latest
-    # archive_progress. That one is rate limited and its final object carries no statistics, so without final
-    # statistics the numbers can be a little behind at the end of a run (and stay at zero for a run shorter
-    # than the update interval).
+    # The statistics come from borg's statistics only: the ones of the final --json output (they also have
+    # the store statistics) are preferred over the latest archive_progress. That one is rate limited, so its
+    # numbers can be a little behind while borg runs; its final object has the final statistics.
     # The --list lines are no source for them: they only exist if the user asked for the listing, and --filter
     # reduces them to some status characters, so counting them would give wrong numbers.
     # What borg does not tell is unknown: there is no archive_progress for a dry-run, and transfer has no
@@ -217,13 +216,9 @@ def feed(self, event):
                 self.archive_counts[event.status] += 1
                 self._add_line(Line(event.message, "archive", event.status))
             case ArchiveProgress():
-                if event.finished:
-                    # the final object carries no statistics, keep the previous ones.
-                    self.archive_finished = True
-                    self.progress_text = ""
-                else:
-                    self.archive_progress = event
-                    self.progress_text = event.path or ""
+                self.archive_progress = event  # the final object has the final statistics (and no path)
+                self.archive_finished = event.finished
+                self.progress_text = event.path or ""
             case ProgressPercent() | ProgressMessage():
                 self._feed_phase(event)
             case Question():

src/borg/testsuite/archive_test.py

@@ -170,8 +170,10 @@ def test_stats_progress_json(stats):
     assert isinstance(result["time"], float)
     assert result["finished"] is True  # see #6570
     assert "path" not in result
-    assert "original_size" not in result
-    assert "nfiles" not in result
+    # the final object has the final statistics
+    assert result["original_size"] == 20
+    assert result["deduplicated_size"] == 20
+    assert result["nfiles"] == 1
 
 
 def test_stats_as_dict(stats):

src/borg/testsuite/archiver/create_cmd_test.py

@@ -739,6 +739,20 @@ def test_progress_on(archivers, request):
     assert "0 B O 0 B U 0 N" in output
 
 
+def test_progress_json_final_statistics(archivers, request):
+    archiver = request.getfixturevalue(archivers)
+    create_regular_file(archiver.input_path, "file1", size=1024 * 80)
+    create_regular_file(archiver.input_path, "file2", size=1024)
+    cmd(archiver, "repo-create", RK_ENCRYPTION)
+    output = cmd(archiver, "create", "test", "input", "--progress", "--log-json")
+    messages = [json.loads(line) for line in output.splitlines() if line.startswith("{")]
+    final = [msg for msg in messages if msg["type"] == "archive_progress"][-1]
+    # the progress is rate limited, so only the final object tells about everything that was processed.
+    assert final["finished"] and "path" not in final
+    assert final["nfiles"] == 2 and final["original_size"] == 1024 * 81
+    assert final["files_stats"] == {"A": 2, "d": 1}
+
+
 def test_progress_off(archivers, request):
     archiver = request.getfixturevalue(archivers)
     create_regular_file(archiver.input_path, "file1", size=1024 * 80)

src/borg/testsuite/archiver/recreate_cmd_test.py

@@ -345,6 +345,8 @@ def test_recreate_progress_json(archivers, request):
     assert len(progress) >= 2
     assert not progress[0]["finished"] and progress[-1]["finished"]
     assert {"nfiles", "original_size", "deduplicated_size", "path"} <= set(progress[0])
+    # the final object has the final statistics: file2 was excluded.
+    assert progress[-1]["nfiles"] == 1 and progress[-1]["files_stats"] == {"A": 1, "d": 1}
     # ... and not of text lines like "1.02 kB O 0 B U 1 N input/file1".
     assert not any(re.search(r" O .* U \d+ N ", line) for line in lines if not line.startswith("{"))
 

src/borg/testsuite/archiver/tar_cmds_test.py

@@ -214,6 +214,12 @@ def test_import_tar_files_stats(archivers, request):
     assert stats["files_stats"] == {"A": 2, "h": 1, "d": 1, "s": 1}
     output = cmd(archiver, "import-tar", "--stats", "dst2", "input.tar")
     assert "Added files: 2" in output
+    # the final archive_progress object has the final statistics
+    output = cmd(archiver, "import-tar", "--log-json", "--progress", "dst3", "input.tar")
+    messages = [json.loads(line) for line in output.splitlines() if line.startswith("{")]
+    final = [msg for msg in messages if msg["type"] == "archive_progress"][-1]
+    assert final["finished"] and final["nfiles"] == 3
+    assert final["files_stats"] == {"A": 2, "h": 1, "d": 1, "s": 1}
 
 
 def test_import_tar_json(archivers, request):