test re-replication

tests/test_encryption.py

@@ -49,12 +49,12 @@ class TestZfsEncryption(unittest2.TestCase):
         self.prepare_encrypted_dataset("22222222", "test_target1/encryptedtarget")
 
         with patch('time.strftime', return_value="20101111000000"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --no-snapshot --exclude-received".split(" ")).run())
 
         with patch('time.strftime', return_value="20101111000001"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --no-snapshot --exclude-received".split(" ")).run())
 
         r = shelltest("zfs get -r -t filesystem encryptionroot test_target1")
         self.assertMultiLineEqual(r,"""
@@ -86,12 +86,12 @@ test_target1/test_source2/fs2/sub                                     encryption
         self.prepare_encrypted_dataset("22222222", "test_target1/encryptedtarget")
 
         with patch('time.strftime', return_value="20101111000000"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --decrypt --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --decrypt --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --decrypt --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --decrypt --no-snapshot --exclude-received".split(" ")).run())
 
         with patch('time.strftime', return_value="20101111000001"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --decrypt --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --decrypt --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --decrypt --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --decrypt --no-snapshot --exclude-received".split(" ")).run())
 
         r = shelltest("zfs get -r -t filesystem encryptionroot test_target1")
         self.assertEqual(r, """
@@ -121,12 +121,12 @@ test_target1/test_source2/fs2/sub                              encryptionroot  -
         self.prepare_encrypted_dataset("22222222", "test_target1/encryptedtarget")
 
         with patch('time.strftime', return_value="20101111000000"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --encrypt --debug --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --encrypt --debug --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --encrypt --debug --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --encrypt --debug --no-snapshot --exclude-received".split(" ")).run())
 
         with patch('time.strftime', return_value="20101111000001"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --encrypt --debug --allow-empty".split(" ")).run())
-            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --encrypt --debug --no-snapshot".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --verbose --no-progress --encrypt --debug --allow-empty --exclude-received".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1/encryptedtarget --verbose --no-progress --encrypt --debug --no-snapshot --exclude-received".split(" ")).run())
 
         r = shelltest("zfs get -r -t filesystem encryptionroot test_target1")
         self.assertEqual(r, """
@@ -157,16 +157,16 @@ test_target1/test_source2/fs2/sub                              encryptionroot  -
 
         with patch('time.strftime', return_value="20101111000000"):
             self.assertFalse(ZfsAutobackup(
-                "test test_target1 --verbose --no-progress --decrypt --encrypt --debug --allow-empty".split(" ")).run())
+                "test test_target1 --verbose --no-progress --decrypt --encrypt --debug --allow-empty --exclude-received".split(" ")).run())
             self.assertFalse(ZfsAutobackup(
-                "test test_target1/encryptedtarget --verbose --no-progress --decrypt --encrypt --debug --no-snapshot".split(
+                "test test_target1/encryptedtarget --verbose --no-progress --decrypt --encrypt --debug --no-snapshot --exclude-received".split(
                     " ")).run())
 
         with patch('time.strftime', return_value="20101111000001"):
             self.assertFalse(ZfsAutobackup(
-                "test test_target1 --verbose --no-progress --decrypt --encrypt --debug --allow-empty".split(" ")).run())
+                "test test_target1 --verbose --no-progress --decrypt --encrypt --debug --allow-empty --exclude-received".split(" ")).run())
             self.assertFalse(ZfsAutobackup(
-                "test test_target1/encryptedtarget --verbose --no-progress --decrypt --encrypt --debug --no-snapshot".split(
+                "test test_target1/encryptedtarget --verbose --no-progress --decrypt --encrypt --debug --no-snapshot --exclude-received".split(
                     " ")).run())
 
         r = shelltest("zfs get -r -t filesystem encryptionroot test_target1")

tests/test_zfsautobackup.py

@@ -590,10 +590,10 @@ test_target1/test_source2/fs2/sub@test-20101111000003
         #test all ssh directions
 
         with patch('time.strftime', return_value="20101111000000"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --no-progress --verbose --allow-empty --ssh-source localhost".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --no-progress --verbose --allow-empty --ssh-source localhost --exclude-received".split(" ")).run())
 
         with patch('time.strftime', return_value="20101111000001"):
-            self.assertFalse(ZfsAutobackup("test test_target1 --no-progress --verbose --allow-empty --ssh-target localhost".split(" ")).run())
+            self.assertFalse(ZfsAutobackup("test test_target1 --no-progress --verbose --allow-empty --ssh-target localhost --exclude-received".split(" ")).run())
 
         with patch('time.strftime', return_value="20101111000002"):
             self.assertFalse(ZfsAutobackup("test test_target1 --no-progress --verbose --allow-empty --ssh-source localhost --ssh-target localhost".split(" ")).run())

tests/test_zfsautobackup31.py

@@ -47,3 +47,27 @@ test_target1/test_source2/fs2/sub@test-20101111000001
 """)
 
 
+    def test_re_replication(self):
+        """test re-replication of something thats already a backup (new in v3.1-beta5)"""
+
+        shelltest("zfs create test_target1/a")
+        shelltest("zfs create test_target1/b")
+
+        with patch('time.strftime', return_value="20101111000000"):
+            self.assertFalse(ZfsAutobackup("test test_target1/a --no-progress --verbose --debug".split(" ")).run())
+
+        with patch('time.strftime', return_value="20101111000001"):
+            self.assertFalse(ZfsAutobackup("test test_target1/b --no-progress --verbose".split(" ")).run())
+
+            r=shelltest("zfs list -H -o name -r -t snapshot test_target1")
+            #NOTE: it wont backup test_target1/a/test_source2/fs2/sub to test_target1/b since it doesnt have the zfs_autobackup property anymore.
+            self.assertMultiLineEqual(r,"""
+test_target1/a/test_source1/fs1@test-20101111000000
+test_target1/a/test_source1/fs1/sub@test-20101111000000
+test_target1/a/test_source2/fs2/sub@test-20101111000000
+test_target1/b/test_source1/fs1@test-20101111000000
+test_target1/b/test_source1/fs1/sub@test-20101111000000
+test_target1/b/test_source2/fs2/sub@test-20101111000000
+test_target1/b/test_target1/a/test_source1/fs1@test-20101111000000
+test_target1/b/test_target1/a/test_source1/fs1/sub@test-20101111000000
+""")

tests/test_zfsnode.py

@@ -16,7 +16,7 @@ class TestZfsNode(unittest2.TestCase):
         node=ZfsNode("test", logger, description=description)
 
         with self.subTest("first snapshot"):
-            node.consistent_snapshot(node.selected_datasets, "test-1",100000)
+            node.consistent_snapshot(node.selected_datasets(exclude_paths=[], exclude_received=False), "test-1",100000)
             r=shelltest("zfs list -H -o name -r -t all "+TEST_POOLS)
             self.assertEqual(r,"""
 test_source1
@@ -35,7 +35,7 @@ test_target1
 
 
         with self.subTest("second snapshot, no changes, no snapshot"):
-            node.consistent_snapshot(node.selected_datasets, "test-2",1)
+            node.consistent_snapshot(node.selected_datasets(exclude_paths=[], exclude_received=False), "test-2",1)
             r=shelltest("zfs list -H -o name -r -t all "+TEST_POOLS)
             self.assertEqual(r,"""
 test_source1
@@ -53,7 +53,7 @@ test_target1
 """)
 
         with self.subTest("second snapshot, no changes, empty snapshot"):
-            node.consistent_snapshot(node.selected_datasets, "test-2",0)
+            node.consistent_snapshot(node.selected_datasets(exclude_paths=[], exclude_received=False), "test-2",0)
             r=shelltest("zfs list -H -o name -r -t all "+TEST_POOLS)
             self.assertEqual(r,"""
 test_source1
@@ -78,7 +78,7 @@ test_target1
         logger=LogStub()
         description="[Source]"
         node=ZfsNode("test", logger, description=description)
-        s=pformat(node.selected_datasets)
+        s=pformat(node.selected_datasets(exclude_paths=[], exclude_received=False))
         print(s)
 
         #basics

zfs_autobackup/ExecuteNode.py

@@ -119,7 +119,7 @@ class ExecuteNode(LogStub):
                 self.debug("EXIT   > {}".format(exit_code))
 
             if (valid_exitcodes != []) and (exit_code not in valid_exitcodes):
-             raise (ExecuteError("Command '{}' return exit code '{}' (valid codes: {})".format(" ".join(cmd), exit_code, valid_exitcodes)))
+             raise (ExecuteError("Command '{}' returned exit code {} (valid codes: {})".format(" ".join(cmd), exit_code, valid_exitcodes)))
 
         # add command to pipe
         encoded_cmd = self._remote_cmd(cmd)

zfs_autobackup/LogConsole.py

@@ -46,3 +46,14 @@ class LogConsole:
             else:
                 print("# " + txt)
             sys.stdout.flush()
+
+    def progress(self, txt):
+        """print progress output to stderr (stays on same line)"""
+        self.clear_progress()
+        print(">>> {}\r".format(txt), end='', file=sys.stderr)
+        sys.stderr.flush()
+
+    def clear_progress(self):
+        import colorama
+        print(colorama.ansi.clear_line(), end='', file=sys.stderr)
+        sys.stderr.flush()

zfs_autobackup/ZfsAutobackup.py

@@ -12,8 +12,8 @@ from zfs_autobackup.ThinnerRule import ThinnerRule
 class ZfsAutobackup:
     """main class"""
 
-    VERSION = "3.1-beta4"
-    HEADER = "zfs-autobackup v{} - Copyright 2020 E.H.Eefting (edwin@datux.nl)".format(VERSION)
+    VERSION = "3.1-beta5"
+    HEADER = "zfs-autobackup v{} - (c)2021 E.H.Eefting (edwin@datux.nl)".format(VERSION)
 
     def __init__(self, argv, print_arguments=True):
 
@@ -59,7 +59,6 @@ class ZfsAutobackup:
                             help='Ignore datasets that seem to be replicated some other way. (No changes since '
                                  'lastest snapshot. Useful for proxmox HA replication)')
 
-        parser.add_argument('--resume', action='store_true', help=argparse.SUPPRESS)
         parser.add_argument('--strip-path', metavar='N', default=0, type=int,
                             help='Number of directories to strip from target path (use 1 when cloning zones between 2 '
                                  'SmartOS machines)')
@@ -89,8 +88,6 @@ class ZfsAutobackup:
         parser.add_argument('--ignore-transfer-errors', action='store_true',
                             help='Ignore transfer errors (still checks if received filesystem exists. useful for '
                                  'acltype errors)')
-        parser.add_argument('--raw', action='store_true',
-                            help=argparse.SUPPRESS)
 
         parser.add_argument('--decrypt', action='store_true',
                             help='Decrypt data before sending it over.')
@@ -108,7 +105,8 @@ class ZfsAutobackup:
                             help='Show zfs commands and their output/exit codes. (noisy)')
         parser.add_argument('--progress', action='store_true',
                             help='show zfs progress output. Enabled automaticly on ttys. (use --no-progress to disable)')
-        parser.add_argument('--no-progress', action='store_true', help=argparse.SUPPRESS)  # needed to workaround a zfs recv -v bug
+        parser.add_argument('--no-progress', action='store_true',
+                            help=argparse.SUPPRESS)  # needed to workaround a zfs recv -v bug
 
         parser.add_argument('--send-pipe', metavar="COMMAND", default=[], action='append',
                             help='pipe zfs send output through COMMAND')
@@ -116,6 +114,11 @@ class ZfsAutobackup:
         parser.add_argument('--recv-pipe', metavar="COMMAND", default=[], action='append',
                             help='pipe zfs recv input through COMMAND')
 
+        parser.add_argument('--resume', action='store_true', help=argparse.SUPPRESS)
+        parser.add_argument('--raw', action='store_true', help=argparse.SUPPRESS)
+        parser.add_argument('--exclude-received', action='store_true',
+                            help=argparse.SUPPRESS)  # probably never needed anymore
+
         # note args is the only global variable we use, since its a global readonly setting anyway
         args = parser.parse_args(argv)
 
@@ -143,7 +146,8 @@ class ZfsAutobackup:
             self.verbose("NOTE: The --resume option isn't needed anymore (its autodetected now)")
 
         if args.raw:
-            self.verbose("NOTE: The --raw option isn't needed anymore (its autodetected now). Use --decrypt to explicitly send data decrypted.")
+            self.verbose(
+                "NOTE: The --raw option isn't needed anymore (its autodetected now). Also see --encrypt and --decrypt.")
 
         if args.target_path is not None and args.target_path[0] == "/":
             self.log.error("Target should not start with a /")
@@ -162,31 +166,54 @@ class ZfsAutobackup:
         self.log.verbose("")
         self.log.verbose("#### " + title)
 
+    def progress(self, txt):
+        self.log.progress(txt)
+
+    def clear_progress(self):
+        self.log.clear_progress()
+
     # NOTE: this method also uses self.args. args that need extra processing are passed as function parameters:
     def thin_missing_targets(self, target_dataset, used_target_datasets):
         """thin target datasets that are missing on the source."""
 
         self.debug("Thinning obsolete datasets")
+        missing_datasets = [dataset for dataset in target_dataset.recursive_datasets if
+                            dataset not in used_target_datasets]
+
+        count = 0
+        for dataset in missing_datasets:
+
+            count = count + 1
+            if self.args.progress:
+                self.progress("Analysing missing {}/{}".format(count, len(missing_datasets)))
 
-        for dataset in target_dataset.recursive_datasets:
             try:
-                if dataset not in used_target_datasets:
                 dataset.debug("Missing on source, thinning")
                 dataset.thin()
 
             except Exception as e:
                 dataset.error("Error during thinning of missing datasets ({})".format(str(e)))
 
+        if self.args.progress:
+            self.clear_progress()
+
     # NOTE: this method also uses self.args. args that need extra processing are passed as function parameters:
     def destroy_missing_targets(self, target_dataset, used_target_datasets):
         """destroy target datasets that are missing on the source and that meet the requirements"""
 
         self.debug("Destroying obsolete datasets")
 
-        for dataset in target_dataset.recursive_datasets:
-            try:
-                if dataset not in used_target_datasets:
+        missing_datasets = [dataset for dataset in target_dataset.recursive_datasets if
+                            dataset not in used_target_datasets]
 
+        count = 0
+        for dataset in missing_datasets:
+
+            count = count + 1
+            if self.args.progress:
+                self.progress("Analysing destroy missing {}/{}".format(count, len(missing_datasets)))
+
+            try:
                 # cant do anything without our own snapshots
                 if not dataset.our_snapshots:
                     if dataset.datasets:
@@ -229,6 +256,9 @@ class ZfsAutobackup:
             except Exception as e:
                 dataset.error("Error during --destroy-missing: {}".format(str(e)))
 
+        if self.args.progress:
+            self.clear_progress()
+
     # NOTE: this method also uses self.args. args that need extra processing are passed as function parameters:
     def sync_datasets(self, source_node, source_datasets, target_node):
         """Sync datasets, or thin-only on both sides
@@ -238,9 +268,15 @@ class ZfsAutobackup:
         """
 
         fail_count = 0
+        count = 0
         target_datasets = []
         for source_dataset in source_datasets:
 
+            # stats
+            if self.args.progress:
+                count = count + 1
+                self.progress("Analysing dataset {}/{} ({} failed)".format(count, len(source_datasets), fail_count))
+
             try:
                 # determine corresponding target_dataset
                 target_name = self.args.target_path + "/" + source_dataset.lstrip_path(self.args.strip_path)
@@ -268,14 +304,19 @@ class ZfsAutobackup:
                                               also_other_snapshots=self.args.other_snapshots,
                                               no_send=self.args.no_send,
                                               destroy_incompatible=self.args.destroy_incompatible,
-                                              output_pipes=self.args.send_pipe, input_pipes=self.args.recv_pipe, decrypt=self.args.decrypt, encrypt=self.args.encrypt)
+                                              output_pipes=self.args.send_pipe, input_pipes=self.args.recv_pipe,
+                                              decrypt=self.args.decrypt, encrypt=self.args.encrypt)
             except Exception as e:
                 fail_count = fail_count + 1
                 source_dataset.error("FAILED: " + str(e))
                 if self.args.debug:
                     raise
 
+        if self.args.progress:
+            self.clear_progress()
+
         target_path_dataset = ZfsDataset(target_node, self.args.target_path)
+        if not self.args.no_thinning:
             self.thin_missing_targets(target_dataset=target_path_dataset, used_target_datasets=target_datasets)
 
         if self.args.destroy_missing is not None:
@@ -285,7 +326,6 @@ class ZfsAutobackup:
 
     def thin_source(self, source_datasets):
 
-        if not self.args.no_thinning:
         self.set_title("Thinning source")
 
         for source_dataset in source_datasets:
@@ -337,6 +377,7 @@ class ZfsAutobackup:
             if self.args.test:
                 self.verbose("TEST MODE - SIMULATING WITHOUT MAKING ANY CHANGES")
 
+            ################ create source zfsNode
             self.set_title("Source settings")
 
             description = "[Source]"
@@ -352,8 +393,24 @@ class ZfsAutobackup:
                 "'autobackup:{}=child')".format(
                     self.args.backup_name, self.args.backup_name))
 
+            ################# select source datasets
             self.set_title("Selecting")
-            selected_source_datasets = source_node.selected_datasets
+
+            #Note: Before version v3.1-beta5, we always used exclude_received. This was a problem if you wanto to replicate an existing backup to another host and use the same backupname/snapshots.
+            exclude_paths = []
+            exclude_received=self.args.exclude_received
+            if self.args.ssh_source == self.args.ssh_target:
+                if self.args.target_path:
+                    # target and source are the same, make sure to exclude target_path
+                    source_node.verbose("NOTE: Source and target are on the same host, excluding target-path")
+                    exclude_paths.append(self.args.target_path)
+                else:
+                    source_node.verbose("NOTE: Source and target are on the same host, excluding received datasets.")
+                    exclude_received=True
+
+
+            selected_source_datasets = source_node.selected_datasets(exclude_received=exclude_received,
+                                                                     exclude_paths=exclude_paths)
             if not selected_source_datasets:
                 self.error(
                     "No source filesystems selected, please do a 'zfs set autobackup:{0}=true' on the source datasets "
@@ -364,11 +421,13 @@ class ZfsAutobackup:
             # filter out already replicated stuff?
             source_datasets = self.filter_replicated(selected_source_datasets)
 
+            ################# snapshotting
             if not self.args.no_snapshot:
                 self.set_title("Snapshotting")
                 source_node.consistent_snapshot(source_datasets, source_node.new_snapshotname(),
                                                 min_changed_bytes=self.args.min_change)
 
+            ################# sync
             # if target is specified, we sync the datasets, otherwise we just thin the source. (e.g. snapshot mode)
             if self.args.target_path:
 
@@ -402,6 +461,7 @@ class ZfsAutobackup:
 
             # no target specified, run in snapshot-only mode
             else:
+                if not self.args.no_thinning:
                     self.thin_source(source_datasets)
                 fail_count = 0
 

zfs_autobackup/ZfsDataset.py

@@ -1,5 +1,4 @@
 import re
-import subprocess
 import time
 
 from zfs_autobackup.CachedProperty import CachedProperty
@@ -113,15 +112,16 @@ class ZfsDataset:
         """true if this dataset is a snapshot"""
         return self.name.find("@") != -1
 
-    def is_selected(self, value, source, inherited, ignore_received):
+    def is_selected(self, value, source, inherited, exclude_received, exclude_paths):
         """determine if dataset should be selected for backup (called from
         ZfsNode)
 
         Args:
+            :type exclude_paths: list of str
             :type value: str
             :type source: str
             :type inherited: bool
-            :type ignore_received: bool
+            :type exclude_received: bool
         """
 
         # sanity checks
@@ -129,22 +129,30 @@ class ZfsDataset:
             # probably a program error in zfs-autobackup or new feature in zfs
             raise (Exception(
                 "{} autobackup-property has illegal source: '{}' (possible BUG)".format(self.name, source)))
+
         if value not in ["false", "true", "child", "-"]:
             # user error
             raise (Exception(
                 "{} autobackup-property has illegal value: '{}'".format(self.name, value)))
 
+        # our path starts with one of the excluded paths?
+        for exclude_path in exclude_paths:
+            if self.name.startswith(exclude_path):
+                # too noisy for verbose
+                self.debug("Excluded (in exclude list)")
+                return False
+
         # now determine if its actually selected
         if value == "false":
-            self.verbose("Ignored (disabled)")
+            self.verbose("Excluded (disabled)")
             return False
         elif value == "true" or (value == "child" and inherited):
             if source == "local":
                 self.verbose("Selected")
                 return True
             elif source == "received":
-                if ignore_received:
-                    self.verbose("Ignored (local backup)")
+                if exclude_received:
+                    self.verbose("Excluded (dataset already received)")
                     return False
                 else:
                     self.verbose("Selected")
@@ -564,7 +572,6 @@ class ZfsDataset:
 
         return self.zfs_node.run(cmd, pipe=True, readonly=True)
 
-
     def recv_pipe(self, pipe, features, filter_properties=None, set_properties=None, ignore_exit_code=False):
         """starts a zfs recv for this snapshot and uses pipe as input
 
@@ -977,7 +984,6 @@ class ZfsDataset:
             :type ignore_recv_exit_code: bool
             :type holds: bool
             :type rollback: bool
-            :type raw: bool
             :type decrypt: bool
             :type also_other_snapshots: bool
             :type no_send: bool

zfs_autobackup/ZfsNode.py

@@ -128,9 +128,8 @@ class ZfsNode(ExecuteNode):
                         bytes_left = self._progress_total_bytes - bytes_
                         minutes_left = int((bytes_left / (bytes_ / (time.time() - self._progress_start_time))) / 60)
 
-                        print(">>> {}% {}MB/s (total {}MB, {} minutes left)     \r".format(percentage, speed, int(
-                            self._progress_total_bytes / (1024 * 1024)), minutes_left), end='', file=sys.stderr)
-                        sys.stderr.flush()
+                        self.logger.progress("Transfer {}% {}MB/s (total {}MB, {} minutes left)".format(percentage, speed, int(
+                            self._progress_total_bytes / (1024 * 1024)), minutes_left))
 
             return
 
@@ -198,8 +197,7 @@ class ZfsNode(ExecuteNode):
             self.verbose("Creating snapshots {} in pool {}".format(snapshot_name, pool_name))
             self.run(cmd, readonly=False)
 
-    @CachedProperty
-    def selected_datasets(self, ignore_received=True):
+    def selected_datasets(self, exclude_received, exclude_paths):
         """determine filesystems that should be backupped by looking at the special autobackup-property, systemwide
 
            returns: list of ZfsDataset
@@ -234,7 +232,7 @@ class ZfsNode(ExecuteNode):
                 source = raw_source
 
             # determine it
-            if dataset.is_selected(value=value, source=source, inherited=inherited, ignore_received=ignore_received):
+            if dataset.is_selected(value=value, source=source, inherited=inherited, exclude_received=exclude_received, exclude_paths=exclude_paths):
                 selected_filesystems.append(dataset)
 
         return selected_filesystems