Implement the progress reporting

src/allmydata/scripts/tahoe_backup.py

@@ -125,6 +125,7 @@ class BackerUpper:
             upload_directory=self.upload_directory,
             targets=targets,
             start_timestamp=start_timestamp,
+            stdout=stdout,
         )
         new_backup_dircap = completed.dircap
 
@@ -312,8 +313,9 @@ def run_backup(
         upload_directory,
         targets,
         start_timestamp,
+        stdout,
 ):
-    progress = BackupProgress(warn, start_timestamp)
+    progress = BackupProgress(warn, start_timestamp, len(targets))
     for target in targets:
         # Pass in the progress and get back a progress.  It would be great if
         # progress objects were immutable.  Then the target's backup would
@@ -321,7 +323,7 @@ def run_backup(
         # Currently, BackupProgress is mutable, though, and everything just
         # mutates it.
         progress = target.backup(progress, upload_file, upload_directory)
-        progress.report()
+        print >>stdout, progress.report(datetime.datetime.now())
     return progress.backup_finished()
 
 
@@ -473,9 +475,10 @@ class BackupProgress(object):
     # Would be nice if this data structure were immutable and its methods were
     # transformations that created a new slightly different object.  Not there
     # yet, though.
-    def __init__(self, warn, start_timestamp):
+    def __init__(self, warn, start_timestamp, target_count):
         self._warn = warn
         self._start_timestamp = start_timestamp
+        self._target_count = target_count
         self._files_created = 0
         self._files_reused = 0
         self._files_skipped = 0
@@ -487,10 +490,35 @@ class BackupProgress(object):
         self._compare_contents = {}
 
 
-    def report(self):
-        pass
+    def report(self, now):
+        report_format = (
+            "Backing up {target_progress}/{target_total}... {elapsed} elapsed..."
+        )
+        return report_format.format(
+            target_progress=(
+                self._files_created
+                + self._files_reused
+                + self._files_skipped
+                + self._directories_created
+                + self._directories_reused
+                + self._directories_skipped
+            ),
+            target_total=self._target_count,
+            elapsed=self._format_elapsed(now - self._start_timestamp),
+        )
 
 
+    def _format_elapsed(self, elapsed):
+        seconds = elapsed.total_seconds()
+        hours = int(seconds / 3600)
+        minutes = int(seconds / 60 % 60)
+        seconds = int(seconds % 60)
+        return "{}h {}m {}s".format(
+            hours,
+            minutes,
+            seconds,
+        )
+
     def backup_finished(self):
         end_timestamp = datetime.datetime.now()
         return BackupComplete(

src/allmydata/test/cli/test_backup.py

@@ -1,6 +1,7 @@
 
 import os.path
 from cStringIO import StringIO
+from datetime import timedelta
 import re
 
 from twisted.trial import unittest
@@ -36,6 +37,19 @@ class Backup(GridTestMixin, CLITestMixin, StallMixin, unittest.TestCase):
         mo = re.search(r"(\d)+ files checked, (\d+) directories checked", out)
         return [int(s) for s in mo.groups()]
 
+    def progress_output(self, out):
+        def parse_timedelta(h, m, s):
+            return timedelta(int(h), int(m), int(s))
+        mos = re.findall(
+            r"Backing up (\d)+/(\d)+\.\.\. (\d+)h (\d+)m (\d+)s elapsed\.\.\.",
+            out,
+        )
+        return list(
+            (int(progress), int(total), parse_timedelta(h, m, s))
+            for (progress, total, h, m, s)
+            in mos
+        )
+
     def test_backup(self):
         self.basedir = "cli/Backup/backup"
         self.set_up_grid(oneshare=True)
@@ -66,8 +80,6 @@ class Backup(GridTestMixin, CLITestMixin, StallMixin, unittest.TestCase):
 
         d.addCallback(lambda res: do_backup(True))
         def _check0((rc, out, err)):
-            print()
-            print(out)
             self.failUnlessReallyEqual(err, "")
             self.failUnlessReallyEqual(rc, 0)
             (
@@ -92,6 +104,34 @@ class Backup(GridTestMixin, CLITestMixin, StallMixin, unittest.TestCase):
             (files_checked, directories_checked) = self.count_output2(out)
             self.failUnlessReallyEqual(files_checked, 0)
             self.failUnlessReallyEqual(directories_checked, 0)
+
+            progress = self.progress_output(out)
+            for left, right in zip(progress[:-1], progress[1:]):
+                # Progress as measured by file count should progress
+                # monotonically.
+                self.assertTrue(
+                    left[0] < right[0],
+                    "Failed: {} < {}".format(left[0], right[0]),
+                )
+
+                # Total work to do should remain the same.
+                self.assertEqual(left[1], right[1])
+
+                # Amount of elapsed time should only go up.  Allow it to
+                # remain the same to account for resolution of the report.
+                self.assertTrue(
+                    left[2] <= right[2],
+                    "Failed: {} <= {}".format(left[2], right[2]),
+                )
+
+            for element in progress:
+                # Can't have more progress than the total.
+                self.assertTrue(
+                    element[0] <= element[1],
+                    "Failed: {} <= {}".format(element[0], element[1]),
+                )
+
+
         d.addCallback(_check0)
 
         d.addCallback(lambda res: self.do_cli("ls", "--uri", "tahoe:backups"))