Merge lp:~fo0bar/turku/turku-storage-log-output into lp:turku

[Ryan Finnie]

Log run output directly to logger

Python 2.7 made real-time logging of subprocess piped output difficult
(and actually a bit dangerous). But now that Turku is Python 3, Popen's
context manager will DTRT and clean up after itself, so we don't need an
intermediary.

Note that this removes return_output from run_logging(), but
return_output was not actually used.

[🤖 Canonical IS Merge Bot (canonical-is-mergebot)]

This merge proposal is being monitored by mergebot. Change the status to Approved to merge.

[lp:~fo0bar/turku/turku-storage-log-output]

39. By Ryan Finnie on 2020-06-21

Mega-noop cleanup

- Add stub README
- Sort imports
- Create MANIFEST.in so `setup.py sdist` produces usable tarballs
- Create stub tests
- Add tox.ini
- Add blank requirements.txt
- Add Makefile
- make black
- Update .bzrignore
- Clean up flake8:
  - setup.py: 'sys' imported but unused
  - ping.py: 're' imported but unused
  - ping.py: ambiguous variable name 'l'
  - utils.py: invalid escape sequence '\d'

40. By Ryan Finnie on 2020-06-21

Log run output directly to logger

Python 2.7 made real-time logging of subprocess piped output difficult
(and actually a bit dangerous). But now that Turku is Python 3, Popen's
context manager will DTRT and clean up after itself, so we don't need an
intermediary.

Note that this removes return_output from run_logging(), but
return_output was not actually used.

Unmerged revisions

=== modified file '.bzrignore'
--- .bzrignore	2015-02-25 01:17:29 +0000
+++ .bzrignore	2020-06-21 22:41:04 +0000
@@ -1,4 +1,61 @@
+MANIFEST
+.pybuild/
+.pytest_cache/
+
+# Byte-compiled / optimized / DLL files
+__pycache__/
+*.py[cod]
+
+# C extensions
+*.so
+
+# Distribution / packaging
+.Python
+env/
 build/
+develop-eggs/
 dist/
-*.pyc
-MANIFEST
+downloads/
+eggs/
+.eggs/
+lib/
+lib64/
+parts/
+sdist/
+var/
+*.egg-info/
+.installed.cfg
+*.egg
+
+# PyInstaller
+#  Usually these files are written by a python script from a template
+#  before PyInstaller builds the exe, so as to inject date/other infos into it.
+*.manifest
+*.spec
+
+# Installer logs
+pip-log.txt
+pip-delete-this-directory.txt
+
+# Unit test / coverage reports
+htmlcov/
+.tox/
+.coverage
+.coverage.*
+.cache
+nosetests.xml
+coverage.xml
+*,cover
+
+# Translations
+*.mo
+*.pot
+
+# Django stuff:
+*.log
+
+# Sphinx documentation
+docs/_build/
+
+# PyBuilder
+target/

=== added file 'MANIFEST.in'
--- MANIFEST.in	1970-01-01 00:00:00 +0000
+++ MANIFEST.in	2020-06-21 22:41:04 +0000
@@ -0,0 +1,10 @@
+include Makefile
+include requirements.txt
+include tests/*.py
+include tox.ini
+include turku-storage.cron
+include turku-storage.logrotate
+include turku-storage-ping
+include turku-storage-update-config
+include turku-storage-update-config.service
+include turku-storage-update-config.timer

=== added file 'Makefile'
--- Makefile	1970-01-01 00:00:00 +0000
+++ Makefile	2020-06-21 22:41:04 +0000
@@ -0,0 +1,28 @@
+PYTHON := python3
+
+all: build
+
+build:
+	$(PYTHON) setup.py build
+
+lint:
+	$(PYTHON) -mtox -e flake8
+
+test:
+	$(PYTHON) -mtox
+
+test-quick:
+	$(PYTHON) -mtox -e black,flake8,pytest-quick
+
+black-check:
+	$(PYTHON) -mtox -e black
+
+black:
+	$(PYTHON) -mblack $(CURDIR)
+
+install: build
+	$(PYTHON) setup.py install
+
+clean:
+	$(PYTHON) setup.py clean
+	$(RM) -r build MANIFEST

=== added file 'README'
--- README	1970-01-01 00:00:00 +0000
+++ README	2020-06-21 22:41:04 +0000
@@ -0,0 +1,4 @@
+Turku backups - storage agent
+Copyright 2015-2020 Canonical Ltd.
+
+https://launchpad.net/turku

=== added file 'requirements.txt'
=== modified file 'setup.py'
--- setup.py	2019-05-22 17:35:00 +0000
+++ setup.py	2020-06-21 22:41:04 +0000
@@ -15,22 +15,21 @@
 # You should have received a copy of the GNU General Public License along with
 # this program.  If not, see <http://www.gnu.org/licenses/>.
 
-import sys
 from setuptools import setup
 
 
 setup(
-    name='turku_storage',
-    description='Turku backups - storage units',
-    author='Ryan Finnie',
-    author_email='[e-mail]',
-    url='https://launchpad.net/turku',
-    python_requires='~=3.4',
-    packages=['turku_storage'],
+    name="turku_storage",
+    description="Turku backups - storage units",
+    author="Ryan Finnie",
+    author_email="[e-mail]",
+    url="https://launchpad.net/turku",
+    python_requires="~=3.4",
+    packages=["turku_storage"],
     entry_points={
-        'console_scripts': [
-            'turku-storage-ping = turku_storage.ping:main',
-            'turku-storage-update-config = turku_storage.update_config:main',
-        ],
+        "console_scripts": [
+            "turku-storage-ping = turku_storage.ping:main",
+            "turku-storage-update-config = turku_storage.update_config:main",
+        ]
     },
 )

=== added directory 'tests'
=== added file 'tests/__init__.py'
=== added file 'tests/test_stub.py'
--- tests/test_stub.py	1970-01-01 00:00:00 +0000
+++ tests/test_stub.py	2020-06-21 22:41:04 +0000
@@ -0,0 +1,8 @@
+import unittest
+import warnings
+
+
+class TestStub(unittest.TestCase):
+    def test_stub(self):
+        # pytest doesn't like a tests/ with no tests
+        warnings.warn("Remove this file once unit tests are added")

=== added file 'tox.ini'
--- tox.ini	1970-01-01 00:00:00 +0000
+++ tox.ini	2020-06-21 22:41:04 +0000
@@ -0,0 +1,38 @@
+[tox]
+envlist = black, flake8, pytest
+
+[testenv]
+basepython = python
+
+[testenv:black]
+commands = python -mblack --check .
+deps = black
+
+[testenv:flake8]
+commands = python -mflake8
+deps = flake8
+
+[testenv:pytest]
+commands = python -mpytest --cov=turku_storage --cov-report=term-missing
+deps = pytest
+       pytest-cov
+       -r{toxinidir}/requirements.txt
+
+[testenv:pytest-quick]
+commands = python -mpytest -m "not slow"
+deps = pytest
+       -r{toxinidir}/requirements.txt
+
+[flake8]
+exclude =
+    .git,
+    __pycache__,
+    .tox,
+# TODO: remove C901 once complexity is reduced
+ignore = C901,E203,E231,W503
+max-line-length = 120
+max-complexity = 10
+
+[pytest]
+markers =
+    slow

=== modified file 'turku_storage/ping.py'
--- turku_storage/ping.py	2020-03-24 23:42:59 +0000
+++ turku_storage/ping.py	2020-06-21 22:41:04 +0000
@@ -13,223 +13,258 @@
 # You should have received a copy of the GNU General Public License along with
 # this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import datetime
 import json
+import logging
 import os
+import subprocess
 import sys
-import subprocess
-import datetime
-import re
-import logging
 import tempfile
 import time
-from .utils import load_config, acquire_lock, api_call, random_weighted, get_latest_snapshot, get_snapshots_to_delete
-
-
-class StoragePing():
-    def __init__(self, uuid, config_dir='/etc/turku-storage'):
+
+from .utils import (
+    load_config,
+    acquire_lock,
+    api_call,
+    random_weighted,
+    get_latest_snapshot,
+    get_snapshots_to_delete,
+)
+
+
+class StoragePing:
+    def __init__(self, uuid, config_dir="/etc/turku-storage"):
         self.arg_uuid = uuid
 
         self.config = load_config(config_dir)
-        for k in ('name', 'secret'):
+        for k in ("name", "secret"):
             if k not in self.config:
-                raise Exception('Incomplete config')
+                raise Exception("Incomplete config")
 
-        self.logger = logging.getLogger(self.config['name'])
+        self.logger = logging.getLogger(self.config["name"])
         self.logger.setLevel(logging.DEBUG)
 
         self.lh_console = logging.StreamHandler()
-        self.lh_console_formatter = logging.Formatter('[%(asctime)s %(name)s] %(levelname)s: %(message)s')
+        self.lh_console_formatter = logging.Formatter(
+            "[%(asctime)s %(name)s] %(levelname)s: %(message)s"
+        )
         self.lh_console.setFormatter(self.lh_console_formatter)
         self.lh_console.setLevel(logging.ERROR)
         self.logger.addHandler(self.lh_console)
 
-        self.lh_master = logging.FileHandler(self.config['log_file'])
-        self.lh_master_formatter = logging.Formatter('[%(asctime)s ' + self.arg_uuid + ' %(process)s] %(levelname)s: %(message)s')
+        self.lh_master = logging.FileHandler(self.config["log_file"])
+        self.lh_master_formatter = logging.Formatter(
+            "[%(asctime)s " + self.arg_uuid + " %(process)s] %(levelname)s: %(message)s"
+        )
         self.lh_master.setFormatter(self.lh_master_formatter)
         self.lh_master.setLevel(logging.DEBUG)
         self.logger.addHandler(self.lh_master)
 
-    def run_logging(self, args, loglevel=logging.DEBUG, cwd=None, env=None, return_output=False):
-        self.logger.log(loglevel, 'Running: %s' % repr(args))
-        t = tempfile.NamedTemporaryFile(mode='w+', encoding='UTF-8')
-        self.logger.log(loglevel, '(Command output is in %s until written here at the end)' % t.name)
-        returncode = subprocess.call(args, cwd=cwd, env=env, stdout=t, stderr=t)
-        t.flush()
-        t.seek(0)
-        out = ''
-        for line in t.readlines():
-            if return_output:
-                out = out + line
-            self.logger.log(loglevel, line.rstrip('\n'))
-        t.close()
-        self.logger.log(loglevel, 'Return code: %d' % returncode)
-        if return_output:
-            return (returncode, out)
-        else:
-            return returncode
+    def run_logging(self, args, loglevel=logging.DEBUG, cwd=None, env=None):
+        self.logger.log(loglevel, "Running: %s" % repr(args))
+        with subprocess.Popen(
+            args,
+            cwd=cwd,
+            env=env,
+            encoding="UTF-8",
+            stdout=subprocess.PIPE,
+            stderr=subprocess.STDOUT,
+        ) as proc:
+            with proc.stdout as stdout:
+                for line in iter(stdout.readline, ""):
+                    self.logger.log(loglevel, line.rstrip("\n"))
+        self.logger.log(loglevel, "Return code: %d" % proc.returncode)
+        return proc.returncode
 
     def process_ping(self):
-        jsonin = ''
+        jsonin = ""
         while True:
-            l = sys.stdin.readline()
-            if (l == '.\n') or (not l):
+            line = sys.stdin.readline()
+            if (line == ".\n") or (not line):
                 break
-            jsonin = jsonin + l
+            jsonin = jsonin + line
         try:
             j = json.loads(jsonin)
         except ValueError:
-            raise Exception('Invalid input JSON')
-
-        lock = acquire_lock(os.path.join(self.config['lock_dir'], 'turku-storage-ping-%s.lock' % self.arg_uuid))
-
-        if 'port' not in j:
-            raise Exception('Port required')
-        forwarded_port = int(j['port'])
+            raise Exception("Invalid input JSON")
+
+        lock = acquire_lock(
+            os.path.join(
+                self.config["lock_dir"], "turku-storage-ping-%s.lock" % self.arg_uuid
+            )
+        )
+
+        if "port" not in j:
+            raise Exception("Port required")
+        forwarded_port = int(j["port"])
 
         verbose = False
-        if 'verbose' in j and j['verbose']:
+        if "verbose" in j and j["verbose"]:
             verbose = True
         if verbose:
             self.lh_console.setLevel(logging.INFO)
 
-        if 'action' in j and j['action'] == 'restore':
-            self.logger.info('Restore mode active on port %d.  Good luck.' % forwarded_port)
-            subprocess.call(['/bin/cat'])
+        if "action" in j and j["action"] == "restore":
+            self.logger.info(
+                "Restore mode active on port %d.  Good luck." % forwarded_port
+            )
+            subprocess.call(["/bin/cat"])
             return
 
         api_out = {
-            'storage': {
-                'name': self.config['name'],
-                'secret': self.config['secret'],
-            },
-            'machine': {
-                'uuid': self.arg_uuid,
-            },
+            "storage": {"name": self.config["name"], "secret": self.config["secret"]},
+            "machine": {"uuid": self.arg_uuid},
         }
-        api_reply = api_call(self.config['api_url'], 'storage_ping_checkin', api_out)
+        api_reply = api_call(self.config["api_url"], "storage_ping_checkin", api_out)
 
-        machine = api_reply['machine']
-        scheduled_sources = machine['scheduled_sources']
+        machine = api_reply["machine"]
+        scheduled_sources = machine["scheduled_sources"]
         if len(scheduled_sources) > 0:
-            self.logger.info('Sources to back up: %s' % ', '.join([s for s in scheduled_sources]))
+            self.logger.info(
+                "Sources to back up: %s" % ", ".join([s for s in scheduled_sources])
+            )
         else:
-            self.logger.info('No sources to back up now')
+            self.logger.info("No sources to back up now")
         for source_name in scheduled_sources:
             time_begin = time.time()
             s = scheduled_sources[source_name]
             source_username = None
             source_password = None
-            if ('sources' in j) and (source_name in j['sources']):
-                if ('username' in j['sources'][source_name]) and j['sources'][source_name]['username']:
-                    source_username = j['sources'][source_name]['username']
-                if ('password' in j['sources'][source_name]) and j['sources'][source_name]['password']:
-                    source_password = j['sources'][source_name]['password']
+            if ("sources" in j) and (source_name in j["sources"]):
+                if ("username" in j["sources"][source_name]) and j["sources"][
+                    source_name
+                ]["username"]:
+                    source_username = j["sources"][source_name]["username"]
+                if ("password" in j["sources"][source_name]) and j["sources"][
+                    source_name
+                ]["password"]:
+                    source_password = j["sources"][source_name]["password"]
             else:
-                if ('username' in s) and s['username']:
-                    source_username = s['username']
-                if ('password' in s) and s['password']:
-                    source_password = s['password']
+                if ("username" in s) and s["username"]:
+                    source_username = s["username"]
+                if ("password" in s) and s["password"]:
+                    source_password = s["password"]
             if not (source_username and source_password):
-                self.logger.error('Cannot find authentication for source "%s"' % source_name)
+                self.logger.error(
+                    'Cannot find authentication for source "%s"' % source_name
+                )
                 continue
-            snapshot_mode = self.config['snapshot_mode']
-            if snapshot_mode == 'link-dest':
-                if 'large_rotating_files' in s and s['large_rotating_files']:
-                    snapshot_mode = 'none'
-                if 'large_modifying_files' in s and s['large_modifying_files']:
-                    snapshot_mode = 'none'
-            if 'snapshot_mode' in s and s['snapshot_mode']:
-                snapshot_mode = s['snapshot_mode']
+            snapshot_mode = self.config["snapshot_mode"]
+            if snapshot_mode == "link-dest":
+                if "large_rotating_files" in s and s["large_rotating_files"]:
+                    snapshot_mode = "none"
+                if "large_modifying_files" in s and s["large_modifying_files"]:
+                    snapshot_mode = "none"
+            if "snapshot_mode" in s and s["snapshot_mode"]:
+                snapshot_mode = s["snapshot_mode"]
 
-            var_machines = os.path.join(self.config['var_dir'], 'machines')
+            var_machines = os.path.join(self.config["var_dir"], "machines")
             if not os.path.exists(var_machines):
                 os.makedirs(var_machines)
 
-            if os.path.islink(os.path.join(var_machines, machine['uuid'])):
-                machine_dir = os.readlink(os.path.join(var_machines, machine['uuid']))
+            if os.path.islink(os.path.join(var_machines, machine["uuid"])):
+                machine_dir = os.readlink(os.path.join(var_machines, machine["uuid"]))
             else:
                 weights = {}
-                for volume_name in self.config['volumes']:
-                    v = self.config['volumes'][volume_name]
+                for volume_name in self.config["volumes"]:
+                    v = self.config["volumes"][volume_name]
                     try:
-                        sv = os.statvfs(v['path'])
+                        sv = os.statvfs(v["path"])
                     except OSError:
                         continue
-                    s_t = (sv.f_bsize * sv.f_blocks / 1048576)
-                    s_a = (sv.f_bsize * sv.f_bavail / 1048576)
+                    s_t = sv.f_bsize * sv.f_blocks / 1048576
+                    s_a = sv.f_bsize * sv.f_bavail / 1048576
                     pct_used = (1.0 - float(s_a) / float(s_t)) * 100.0
-                    if (not v['accept_new']) or (pct_used > v['accept_new_high_water_pct']):
+                    if (not v["accept_new"]) or (
+                        pct_used > v["accept_new_high_water_pct"]
+                    ):
                         continue
                     weights[volume_name] = s_a
                 if len(weights) == 0:
-                    raise Exception('Cannot find a suitable storage directory')
+                    raise Exception("Cannot find a suitable storage directory")
                 chosen_volume = random_weighted(weights)
                 if not chosen_volume:
-                    raise Exception('Cannot find a suitable storage directory')
-                machine_dir = os.path.join(self.config['volumes'][chosen_volume]['path'], machine['uuid'])
-                os.symlink(machine_dir, os.path.join(var_machines, machine['uuid']))
+                    raise Exception("Cannot find a suitable storage directory")
+                machine_dir = os.path.join(
+                    self.config["volumes"][chosen_volume]["path"], machine["uuid"]
+                )
+                os.symlink(machine_dir, os.path.join(var_machines, machine["uuid"]))
             if not os.path.exists(machine_dir):
                 os.makedirs(machine_dir)
 
-            machine_symlink = machine['unit_name']
-            if 'service_name' in machine and machine['service_name']:
-                machine_symlink = machine['service_name'] + '-' + machine_symlink
-            if 'environment_name' in machine and machine['environment_name']:
-                machine_symlink = machine['environment_name'] + '-' + machine_symlink
-            machine_symlink = machine_symlink.replace('/', '_')
+            machine_symlink = machine["unit_name"]
+            if "service_name" in machine and machine["service_name"]:
+                machine_symlink = machine["service_name"] + "-" + machine_symlink
+            if "environment_name" in machine and machine["environment_name"]:
+                machine_symlink = machine["environment_name"] + "-" + machine_symlink
+            machine_symlink = machine_symlink.replace("/", "_")
             if os.path.islink(os.path.join(var_machines, machine_symlink)):
                 os.unlink(os.path.join(var_machines, machine_symlink))
             if not os.path.exists(os.path.join(var_machines, machine_symlink)):
-                os.symlink(machine['uuid'], os.path.join(var_machines, machine_symlink))
-
-            self.logger.info('Begin: %s %s' % (machine['unit_name'], source_name))
-
-            rsync_args = ['rsync', '--archive', '--compress', '--numeric-ids', '--delete', '--delete-excluded']
-            rsync_args.append('--verbose')
+                os.symlink(machine["uuid"], os.path.join(var_machines, machine_symlink))
+
+            self.logger.info("Begin: %s %s" % (machine["unit_name"], source_name))
+
+            rsync_args = [
+                "rsync",
+                "--archive",
+                "--compress",
+                "--numeric-ids",
+                "--delete",
+                "--delete-excluded",
+            ]
+            rsync_args.append("--verbose")
 
             dest_dir = os.path.join(machine_dir, source_name)
             if not os.path.exists(dest_dir):
                 os.makedirs(dest_dir)
-            if snapshot_mode == 'link-dest':
-                snapshot_dir = os.path.join(machine_dir, '%s.snapshots' % source_name)
+            if snapshot_mode == "link-dest":
+                snapshot_dir = os.path.join(machine_dir, "%s.snapshots" % source_name)
                 if not os.path.exists(snapshot_dir):
                     os.makedirs(snapshot_dir)
-                dirs = [d for d in os.listdir(snapshot_dir) if os.path.isdir(os.path.join(snapshot_dir, d))]
+                dirs = [
+                    d
+                    for d in os.listdir(snapshot_dir)
+                    if os.path.isdir(os.path.join(snapshot_dir, d))
+                ]
                 base_snapshot = get_latest_snapshot(dirs)
                 if base_snapshot:
-                    rsync_args.append('--link-dest=%s' % os.path.join(snapshot_dir, base_snapshot))
+                    rsync_args.append(
+                        "--link-dest=%s" % os.path.join(snapshot_dir, base_snapshot)
+                    )
             else:
-                rsync_args.append('--inplace')
-            if self.config['preserve_hard_links']:
-                rsync_args.append('--hard-links')
+                rsync_args.append("--inplace")
+            if self.config["preserve_hard_links"]:
+                rsync_args.append("--hard-links")
 
             filter_file = None
-            filter_data = ''
-            if 'filter' in s:
-                for filter in s['filter']:
-                    if filter.startswith('merge') or filter.startswith(':'):
+            filter_data = ""
+            if "filter" in s:
+                for filter in s["filter"]:
+                    if filter.startswith("merge") or filter.startswith(":"):
                         # Do not allow local merges
                         continue
-                    filter_data += '%s\n' % filter
-            if 'exclude' in s:
-                for exclude in s['exclude']:
-                    filter_data += '- %s\n' % exclude
+                    filter_data += "%s\n" % filter
+            if "exclude" in s:
+                for exclude in s["exclude"]:
+                    filter_data += "- %s\n" % exclude
             if filter_data:
-                filter_file = tempfile.NamedTemporaryFile(mode='w+', encoding='UTF-8')
+                filter_file = tempfile.NamedTemporaryFile(mode="w+", encoding="UTF-8")
                 filter_file.write(filter_data)
                 filter_file.flush()
-                rsync_args.append('--filter=merge %s' % filter_file.name)
-
-            if 'bwlimit' in s and s['bwlimit']:
-                rsync_args.append('--bwlimit=%s' % s['bwlimit'])
-
-            rsync_args.append('rsync://%s@127.0.0.1:%d/%s/' % (source_username, forwarded_port, source_name))
-
-            rsync_args.append('%s/' % dest_dir)
-
-            rsync_env = {
-                'RSYNC_PASSWORD': source_password
-            }
+                rsync_args.append("--filter=merge %s" % filter_file.name)
+
+            if "bwlimit" in s and s["bwlimit"]:
+                rsync_args.append("--bwlimit=%s" % s["bwlimit"])
+
+            rsync_args.append(
+                "rsync://%s@127.0.0.1:%d/%s/"
+                % (source_username, forwarded_port, source_name)
+            )
+
+            rsync_args.append("%s/" % dest_dir)
+
+            rsync_env = {"RSYNC_PASSWORD": source_password}
             returncode = self.run_logging(rsync_args, env=rsync_env)
             if returncode in (0, 24):
                 success = True
@@ -241,52 +276,66 @@
             snapshot_name = None
             summary_output = None
             if success:
-                if snapshot_mode == 'link-dest':
-                    summary_output = ''
+                if snapshot_mode == "link-dest":
+                    summary_output = ""
                     if base_snapshot:
-                        summary_output = summary_output + 'Base snapshot: %s\n' % base_snapshot
+                        summary_output = (
+                            summary_output + "Base snapshot: %s\n" % base_snapshot
+                        )
                     snapshot_name = datetime.datetime.now().isoformat()
                     os.rename(dest_dir, os.path.join(snapshot_dir, snapshot_name))
-                    if os.path.islink(os.path.join(snapshot_dir, 'latest')):
-                        os.unlink(os.path.join(snapshot_dir, 'latest'))
-                    if not os.path.exists(os.path.join(snapshot_dir, 'latest')):
-                        os.symlink(snapshot_name, os.path.join(snapshot_dir, 'latest'))
-                    if 'retention' in s:
-                        dirs = [d for d in os.listdir(snapshot_dir) if os.path.isdir(os.path.join(snapshot_dir, d))]
-                        to_delete = get_snapshots_to_delete(s['retention'], dirs)
+                    if os.path.islink(os.path.join(snapshot_dir, "latest")):
+                        os.unlink(os.path.join(snapshot_dir, "latest"))
+                    if not os.path.exists(os.path.join(snapshot_dir, "latest")):
+                        os.symlink(snapshot_name, os.path.join(snapshot_dir, "latest"))
+                    if "retention" in s:
+                        dirs = [
+                            d
+                            for d in os.listdir(snapshot_dir)
+                            if os.path.isdir(os.path.join(snapshot_dir, d))
+                        ]
+                        to_delete = get_snapshots_to_delete(s["retention"], dirs)
                         for snapshot in to_delete:
-                            temp_delete_tree = os.path.join(snapshot_dir, '_delete-%s' % snapshot)
-                            os.rename(os.path.join(snapshot_dir, snapshot), temp_delete_tree)
+                            temp_delete_tree = os.path.join(
+                                snapshot_dir, "_delete-%s" % snapshot
+                            )
+                            os.rename(
+                                os.path.join(snapshot_dir, snapshot), temp_delete_tree
+                            )
                             # Should better handle this
-                            subprocess.call(['rm', '-rf', temp_delete_tree])
-                            summary_output = summary_output + 'Removed old snapshot: %s\n' % snapshot
+                            subprocess.call(["rm", "-rf", temp_delete_tree])
+                            summary_output = (
+                                summary_output + "Removed old snapshot: %s\n" % snapshot
+                            )
             else:
-                summary_output = 'rsync exited with return code %d' % returncode
+                summary_output = "rsync exited with return code %d" % returncode
 
             time_end = time.time()
             api_out = {
-                'storage': {
-                    'name': self.config['name'],
-                    'secret': self.config['secret'],
+                "storage": {
+                    "name": self.config["name"],
+                    "secret": self.config["secret"],
                 },
-                'machine': {
-                    'uuid': self.arg_uuid,
-                    'sources': {
+                "machine": {
+                    "uuid": self.arg_uuid,
+                    "sources": {
                         source_name: {
-                            'success': success,
-                            'snapshot': snapshot_name,
-                            'summary': summary_output,
-                            'time_begin': time_begin,
-                            'time_end': time_end,
-                        },
+                            "success": success,
+                            "snapshot": snapshot_name,
+                            "summary": summary_output,
+                            "time_begin": time_begin,
+                            "time_end": time_end,
+                        }
                     },
                 },
             }
-            api_reply = api_call(self.config['api_url'], 'storage_ping_source_update', api_out)
-
-            self.logger.info('End: %s %s' % (machine['unit_name'], source_name))
-
-        self.logger.info('Done')
+            api_reply = api_call(
+                self.config["api_url"], "storage_ping_source_update", api_out
+            )
+
+            self.logger.info("End: %s %s" % (machine["unit_name"], source_name))
+
+        self.logger.info("Done")
         lock.close()
 
     def main(self):
@@ -301,9 +350,10 @@
     import argparse
 
     parser = argparse.ArgumentParser(
-        formatter_class=argparse.ArgumentDefaultsHelpFormatter)
-    parser.add_argument('--config-dir', '-c', type=str, default='/etc/turku-storage')
-    parser.add_argument('uuid')
+        formatter_class=argparse.ArgumentDefaultsHelpFormatter
+    )
+    parser.add_argument("--config-dir", "-c", type=str, default="/etc/turku-storage")
+    parser.add_argument("uuid")
     return parser.parse_args()
 
 

=== modified file 'turku_storage/update_config.py'
--- turku_storage/update_config.py	2019-05-22 17:35:00 +0000
+++ turku_storage/update_config.py	2020-06-21 22:41:04 +0000
@@ -14,9 +14,10 @@
 # this program.  If not, see <http://www.gnu.org/licenses/>.
 
 import os
+import pwd
+import random
 import time
-import random
-import pwd
+
 from .utils import load_config, acquire_lock, api_call
 
 
@@ -24,9 +25,10 @@
     import argparse
 
     parser = argparse.ArgumentParser(
-        formatter_class=argparse.ArgumentDefaultsHelpFormatter)
-    parser.add_argument('--config-dir', '-c', type=str, default='/etc/turku-storage')
-    parser.add_argument('--wait', '-w', type=float)
+        formatter_class=argparse.ArgumentDefaultsHelpFormatter
+    )
+    parser.add_argument("--config-dir", "-c", type=str, default="/etc/turku-storage")
+    parser.add_argument("--wait", "-w", type=float)
     return parser.parse_args()
 
 
@@ -39,77 +41,84 @@
 
     config = load_config(args.config_dir)
 
-    lock = acquire_lock(os.path.join(config['lock_dir'], 'turku-storage-update-config.lock'))
+    lock = acquire_lock(
+        os.path.join(config["lock_dir"], "turku-storage-update-config.lock")
+    )
 
     space_total = 0
     space_available = 0
     seen_devs = []
-    for volume_name in config['volumes']:
-        v = config['volumes'][volume_name]
-        st_dev = os.stat(v['path']).st_dev
+    for volume_name in config["volumes"]:
+        v = config["volumes"][volume_name]
+        st_dev = os.stat(v["path"]).st_dev
         if st_dev in seen_devs:
             continue
         seen_devs.append(st_dev)
         try:
-            sv = os.statvfs(v['path'])
+            sv = os.statvfs(v["path"])
         except OSError:
             continue
-        s_t = (sv.f_bsize * sv.f_blocks / 1048576)
-        s_a = (sv.f_bsize * sv.f_bavail / 1048576)
+        s_t = sv.f_bsize * sv.f_blocks / 1048576
+        s_a = sv.f_bsize * sv.f_bavail / 1048576
         pct_used = (1.0 - float(s_a) / float(s_t)) * 100.0
-        if (not v['accept_new']) or (pct_used > v['accept_new_high_water_pct']):
+        if (not v["accept_new"]) or (pct_used > v["accept_new_high_water_pct"]):
             s_a = 0
         space_total += s_t
         space_available += s_a
 
     api_out = {
-        'storage': {
-            'name': config['name'],
-            'secret': config['secret'],
-            'ssh_ping_host': config['ssh_ping_host'],
-            'ssh_ping_port': config['ssh_ping_port'],
-            'ssh_ping_user': config['ssh_ping_user'],
-            'ssh_ping_host_keys': config['ssh_ping_host_keys'],
-            'space_total': space_total,
-            'space_available': space_available,
-        },
+        "storage": {
+            "name": config["name"],
+            "secret": config["secret"],
+            "ssh_ping_host": config["ssh_ping_host"],
+            "ssh_ping_port": config["ssh_ping_port"],
+            "ssh_ping_user": config["ssh_ping_user"],
+            "ssh_ping_host_keys": config["ssh_ping_host_keys"],
+            "space_total": space_total,
+            "space_available": space_available,
+        }
     }
-    if ('api_auth_name' in config) and ('api_auth_secret' in config):
-        api_out['auth'] = {
-            'name': config['api_auth_name'],
-            'secret': config['api_auth_secret'],
+    if ("api_auth_name" in config) and ("api_auth_secret" in config):
+        api_out["auth"] = {
+            "name": config["api_auth_name"],
+            "secret": config["api_auth_secret"],
         }
     else:
         # XXX legacy
-        api_out['auth'] = config['api_auth']
-    if 'published' in config:
-        api_out['storage']['published'] = config['published']
-
-    api_reply = api_call(config['api_url'], 'storage_update_config', api_out)
-
-    authorized_keys_out = '# Automatically generated, please do not edit\n'
-    authorized_keys_out += '# Local additions may be placed in %s.static\n' % config['authorized_keys_file']
-    if os.path.isfile(config['authorized_keys_file'] + '.static'):
-        with open(config['authorized_keys_file'] + '.static') as f:
+        api_out["auth"] = config["api_auth"]
+    if "published" in config:
+        api_out["storage"]["published"] = config["published"]
+
+    api_reply = api_call(config["api_url"], "storage_update_config", api_out)
+
+    authorized_keys_out = "# Automatically generated, please do not edit\n"
+    authorized_keys_out += (
+        "# Local additions may be placed in %s.static\n"
+        % config["authorized_keys_file"]
+    )
+    if os.path.isfile(config["authorized_keys_file"] + ".static"):
+        with open(config["authorized_keys_file"] + ".static") as f:
             authorized_keys_out += f.read()
-    for machine_uuid in api_reply['machines']:
-        machine = api_reply['machines'][machine_uuid]
+    for machine_uuid in api_reply["machines"]:
+        machine = api_reply["machines"][machine_uuid]
         authorized_keys_out += '%s,command="%s %s" %s (%s)\n' % (
-            'no-pty,no-agent-forwarding,no-X11-forwarding,no-user-rc',
-            config['authorized_keys_command'], machine_uuid,
-            machine['ssh_public_key'], machine['unit_name']
+            "no-pty,no-agent-forwarding,no-X11-forwarding,no-user-rc",
+            config["authorized_keys_command"],
+            machine_uuid,
+            machine["ssh_public_key"],
+            machine["unit_name"],
         )
 
-    f_uid = pwd.getpwnam(config['authorized_keys_user']).pw_uid
-    f_gid = pwd.getpwnam(config['authorized_keys_user']).pw_gid
-    keys_dirname = os.path.dirname(config['authorized_keys_file'])
+    f_uid = pwd.getpwnam(config["authorized_keys_user"]).pw_uid
+    f_gid = pwd.getpwnam(config["authorized_keys_user"]).pw_gid
+    keys_dirname = os.path.dirname(config["authorized_keys_file"])
     if not os.path.isdir(keys_dirname):
         os.makedirs(keys_dirname)
         os.chown(keys_dirname, f_uid, f_gid)
-    temp_fn = '%s.tmp.%s' % (config['authorized_keys_file'], os.getpid())
-    with open(temp_fn, 'w') as f:
+    temp_fn = "%s.tmp.%s" % (config["authorized_keys_file"], os.getpid())
+    with open(temp_fn, "w") as f:
         os.fchown(f.fileno(), f_uid, f_gid)
         f.write(authorized_keys_out)
-    os.rename(temp_fn, config['authorized_keys_file'])
+    os.rename(temp_fn, config["authorized_keys_file"])
 
     lock.close()

=== modified file 'turku_storage/utils.py'
--- turku_storage/utils.py	2019-10-29 09:47:32 +0000
+++ turku_storage/utils.py	2020-06-21 22:41:04 +0000
@@ -13,34 +13,36 @@
 # You should have received a copy of the GNU General Public License along with
 # this program.  If not, see <http://www.gnu.org/licenses/>.
 
-import os
-import urllib.parse
+import copy
+import datetime
+import glob
 import http.client
 import json
-import copy
+import os
+import pwd
 import random
+import re
 import socket
-import glob
-import pwd
-import datetime
-import re
 import time
-
-
-class RuntimeLock():
+import urllib.parse
+
+
+class RuntimeLock:
     name = None
     file = None
 
     def __init__(self, name):
         import fcntl
-        file = open(name, 'w')
+
+        file = open(name, "w")
         try:
             fcntl.lockf(file, fcntl.LOCK_EX | fcntl.LOCK_NB)
         except IOError as e:
             import errno
+
             if e.errno in (errno.EACCES, errno.EAGAIN):
                 raise
-        file.write('%10s\n' % os.getpid())
+        file.write("%10s\n" % os.getpid())
         file.flush()
         file.seek(0)
         self.name = name
@@ -71,12 +73,12 @@
 
 def json_dump_p(obj, f):
     """Calls json.dump with standard (pretty) formatting"""
-    return json.dump(obj, f, sort_keys=True, indent=4, separators=(',', ': '))
+    return json.dump(obj, f, sort_keys=True, indent=4, separators=(",", ": "))
 
 
 def json_dumps_p(obj):
     """Calls json.dumps with standard (pretty) formatting"""
-    return json.dumps(obj, sort_keys=True, indent=4, separators=(',', ': '))
+    return json.dumps(obj, sort_keys=True, indent=4, separators=(",", ": "))
 
 
 def json_load_file(file):
@@ -103,27 +105,29 @@
 
 def api_call(api_url, cmd, post_data, timeout=5):
     url = urllib.parse.urlparse(api_url)
-    if url.scheme == 'https':
+    if url.scheme == "https":
         h = http.client.HTTPSConnection(url.netloc, timeout=timeout)
     else:
         h = http.client.HTTPConnection(url.netloc, timeout=timeout)
     out = json.dumps(post_data)
-    h.putrequest('POST', '%s/%s' % (url.path, cmd))
-    h.putheader('Content-Type', 'application/json')
-    h.putheader('Content-Length', len(out))
-    h.putheader('Accept', 'application/json')
+    h.putrequest("POST", "%s/%s" % (url.path, cmd))
+    h.putheader("Content-Type", "application/json")
+    h.putheader("Content-Length", len(out))
+    h.putheader("Accept", "application/json")
     h.endheaders()
-    h.send(out.encode('UTF-8'))
+    h.send(out.encode("UTF-8"))
 
     res = h.getresponse()
     if not res.status == http.client.OK:
-        raise Exception('Received error %d (%s) from API server' % (res.status, res.reason))
-    if not res.getheader('content-type') == 'application/json':
-        raise Exception('Received invalid reply from API server')
+        raise Exception(
+            "Received error %d (%s) from API server" % (res.status, res.reason)
+        )
+    if not res.getheader("content-type") == "application/json":
+        raise Exception("Received invalid reply from API server")
     try:
-        return json.loads(res.read().decode('UTF-8'))
+        return json.loads(res.read().decode("UTF-8"))
     except ValueError:
-        raise Exception('Received invalid reply from API server')
+        raise Exception("Received invalid reply from API server")
 
 
 def random_weighted(m):
@@ -144,11 +148,11 @@
 
 def load_config(config_dir):
     config = {}
-    config_d = os.path.join(config_dir, 'config.d')
+    config_d = os.path.join(config_dir, "config.d")
     config_files = [
         os.path.join(config_d, fn)
         for fn in os.listdir(config_d)
-        if fn.endswith('.json')
+        if fn.endswith(".json")
         and os.path.isfile(os.path.join(config_d, fn))
         and os.access(os.path.join(config_d, fn), os.R_OK)
     ]
@@ -156,66 +160,70 @@
     for file in config_files:
         config = dict_merge(config, json_load_file(file))
 
-    required_keys = ['name', 'secret', 'api_url', 'volumes']
+    required_keys = ["name", "secret", "api_url", "volumes"]
     # XXX legacy
-    if 'api_auth' not in config:
-        required_keys += ['api_auth_name', 'api_auth_secret']
+    if "api_auth" not in config:
+        required_keys += ["api_auth_name", "api_auth_secret"]
     for k in required_keys:
         if k not in config:
-            raise Exception('Incomplete config')
-
-    if 'accept_new_high_water_pct' not in config:
-        config['accept_new_high_water_pct'] = 80
-
-    for volume_name in config['volumes']:
-        if 'path' not in config['volumes'][volume_name]:
-            del(config['volumes'][volume_name])
+            raise Exception("Incomplete config")
+
+    if "accept_new_high_water_pct" not in config:
+        config["accept_new_high_water_pct"] = 80
+
+    for volume_name in config["volumes"]:
+        if "path" not in config["volumes"][volume_name]:
+            del config["volumes"][volume_name]
             continue
-        if 'accept_new' not in config['volumes'][volume_name]:
-            config['volumes'][volume_name]['accept_new'] = True
-        if 'accept_new_high_water_pct' not in config['volumes'][volume_name]:
-            config['volumes'][volume_name]['accept_new_high_water_pct'] = config['accept_new_high_water_pct']
-
-    if len(config['volumes']) == 0:
-        raise Exception('Incomplete config')
-
-    if 'log_file' not in config:
-        config['log_file'] = '/var/log/turku-storage.log'
-    if 'lock_dir' not in config:
-        config['lock_dir'] = '/var/lock'
-    if 'var_dir' not in config:
-        config['var_dir'] = '/var/lib/turku-storage'
-
-    if 'snapshot_mode' not in config:
-        config['snapshot_mode'] = 'link-dest'
-    if 'preserve_hard_links' not in config:
-        config['preserve_hard_links'] = False
-
-    if 'ssh_ping_host' not in config:
-        config['ssh_ping_host'] = socket.getfqdn()
-    if 'ssh_ping_port' not in config:
-        config['ssh_ping_port'] = 22
-    if 'ssh_ping_user' not in config:
-        config['ssh_ping_user'] = 'root'
-    if 'ssh_ping_host_keys' not in config:
-        config['ssh_ping_host_keys'] = []
-        keys_glob = '/etc/ssh/ssh_host_*_key.pub'
-        if 'ssh_ping_host_keys_glob' in config:
-            keys_glob = config['ssh_ping_host_keys_glob']
+        if "accept_new" not in config["volumes"][volume_name]:
+            config["volumes"][volume_name]["accept_new"] = True
+        if "accept_new_high_water_pct" not in config["volumes"][volume_name]:
+            config["volumes"][volume_name]["accept_new_high_water_pct"] = config[
+                "accept_new_high_water_pct"
+            ]
+
+    if len(config["volumes"]) == 0:
+        raise Exception("Incomplete config")
+
+    if "log_file" not in config:
+        config["log_file"] = "/var/log/turku-storage.log"
+    if "lock_dir" not in config:
+        config["lock_dir"] = "/var/lock"
+    if "var_dir" not in config:
+        config["var_dir"] = "/var/lib/turku-storage"
+
+    if "snapshot_mode" not in config:
+        config["snapshot_mode"] = "link-dest"
+    if "preserve_hard_links" not in config:
+        config["preserve_hard_links"] = False
+
+    if "ssh_ping_host" not in config:
+        config["ssh_ping_host"] = socket.getfqdn()
+    if "ssh_ping_port" not in config:
+        config["ssh_ping_port"] = 22
+    if "ssh_ping_user" not in config:
+        config["ssh_ping_user"] = "root"
+    if "ssh_ping_host_keys" not in config:
+        config["ssh_ping_host_keys"] = []
+        keys_glob = "/etc/ssh/ssh_host_*_key.pub"
+        if "ssh_ping_host_keys_glob" in config:
+            keys_glob = config["ssh_ping_host_keys_glob"]
         for pubkey in glob.glob(keys_glob):
             with open(pubkey) as f:
-                config['ssh_ping_host_keys'].append(f.read().rstrip())
-    if 'authorized_keys_file' not in config:
-        config['authorized_keys_file'] = '%s/.ssh/authorized_keys' % pwd.getpwnam(config['ssh_ping_user']).pw_dir
-    if 'authorized_keys_user' not in config:
-        config['authorized_keys_user'] = config['ssh_ping_user']
-    if 'authorized_keys_command' not in config:
-        config['authorized_keys_command'] = 'turku-storage-ping'
+                config["ssh_ping_host_keys"].append(f.read().rstrip())
+    if "authorized_keys_file" not in config:
+        config["authorized_keys_file"] = (
+            "%s/.ssh/authorized_keys" % pwd.getpwnam(config["ssh_ping_user"]).pw_dir
+        )
+    if "authorized_keys_user" not in config:
+        config["authorized_keys_user"] = config["ssh_ping_user"]
+    if "authorized_keys_command" not in config:
+        config["authorized_keys_command"] = "turku-storage-ping"
 
-    if 'timezone' not in config:
-        config['timezone'] = 'UTC'
-    if config['timezone']:
-        os.environ['TZ'] = config['timezone']
+    if "timezone" not in config:
+        config["timezone"] = "UTC"
+    if config["timezone"]:
+        os.environ["TZ"] = config["timezone"]
     time.tzset()
 
     return config
@@ -227,23 +235,23 @@
     #     2015-02-20T03:20:36
     #     2015-02-20T03:21:18.152575
     # use it as a timestamp, otherwise ignore it
-    if 'save' in ss:
-        raise ValueError('Excluded snapshot')
-    if ss == 'working':
-        raise ValueError('Excluded snapshot')
+    if "save" in ss:
+        raise ValueError("Excluded snapshot")
+    if ss == "working":
+        raise ValueError("Excluded snapshot")
     try:
-        return datetime.datetime.strptime(ss, '%Y-%m-%dT%H:%M:%S.%f')
+        return datetime.datetime.strptime(ss, "%Y-%m-%dT%H:%M:%S.%f")
     except ValueError:
         pass
     try:
-        return datetime.datetime.strptime(ss, '%Y-%m-%dT%H:%M:%S')
+        return datetime.datetime.strptime(ss, "%Y-%m-%dT%H:%M:%S")
     except ValueError:
         pass
     try:
         return datetime.datetime.utcfromtimestamp(float(ss))
     except ValueError:
         pass
-    raise ValueError('Unknown snapshot name format')
+    raise ValueError("Unknown snapshot name format")
 
 
 def get_latest_snapshot(snapshots):
@@ -268,43 +276,42 @@
 
     now = datetime.datetime.now()
     to_keep = []
-    for ritem in retention.split(','):
+    for ritem in retention.split(","):
         ritem = ritem.strip()
-        r = re.findall('^earliest of (?:(\d+) )?(day|week|month)', ritem)
+        r = re.findall(r"^earliest of (?:(\d+) )?(day|week|month)", ritem)
         if len(r) > 0:
-            if r[0][0] == '':
+            if r[0][0] == "":
                 earliest_num = 1
             else:
                 earliest_num = int(r[0][0])
             earliest_word = r[0][1]
-            if earliest_word == 'fortnight':
-                earliest_word = 'week'
+            if earliest_word == "fortnight":
+                earliest_word = "week"
                 earliest_num = earliest_num * 2
-            if earliest_word == 'day':
-                cutoff_time = (
-                    now.replace(hour=0, minute=0, second=0, microsecond=0) -
-                    datetime.timedelta(days=(earliest_num - 1))
-                )
-            elif earliest_word == 'week':
-                cutoff_time = (
-                    now.replace(hour=0, minute=0, second=0, microsecond=0) -
-                    datetime.timedelta(days=((now.weekday() + 1) % 7))
-                )
-                for i in range(earliest_num - 1):
-                    cutoff_time = (
-                        cutoff_time - datetime.timedelta(weeks=1)
-                    ).replace(day=1, hour=0, minute=0, second=0, microsecond=0)
-            elif earliest_word == 'month':
-                cutoff_time = now.replace(day=1, hour=0, minute=0, second=0, microsecond=0)
-                for i in range(earliest_num - 1):
-                    cutoff_time = (
-                        cutoff_time - datetime.timedelta(days=1)
-                    ).replace(day=1, hour=0, minute=0, second=0, microsecond=0)
+            if earliest_word == "day":
+                cutoff_time = now.replace(
+                    hour=0, minute=0, second=0, microsecond=0
+                ) - datetime.timedelta(days=(earliest_num - 1))
+            elif earliest_word == "week":
+                cutoff_time = now.replace(
+                    hour=0, minute=0, second=0, microsecond=0
+                ) - datetime.timedelta(days=((now.weekday() + 1) % 7))
+                for i in range(earliest_num - 1):
+                    cutoff_time = (cutoff_time - datetime.timedelta(weeks=1)).replace(
+                        day=1, hour=0, minute=0, second=0, microsecond=0
+                    )
+            elif earliest_word == "month":
+                cutoff_time = now.replace(
+                    day=1, hour=0, minute=0, second=0, microsecond=0
+                )
+                for i in range(earliest_num - 1):
+                    cutoff_time = (cutoff_time - datetime.timedelta(days=1)).replace(
+                        day=1, hour=0, minute=0, second=0, microsecond=0
+                    )
             else:
-                cutoff_time = (
-                    now.replace(hour=0, minute=0, second=0, microsecond=0) -
-                    datetime.timedelta(days=(earliest_num - 1))
-                )
+                cutoff_time = now.replace(
+                    hour=0, minute=0, second=0, microsecond=0
+                ) - datetime.timedelta(days=(earliest_num - 1))
             candidate_s = None
             for s in list(snapshot_dict.keys()):
                 if s < cutoff_time:
@@ -317,16 +324,16 @@
                 candidate_s = s
             if candidate_s and candidate_s not in to_keep:
                 to_keep.append(candidate_s)
-        r = re.findall('^last (\d+) day', ritem)
+        r = re.findall(r"^last (\d+) day", ritem)
         if len(r) > 0:
             last_days = int(r[0])
-            cutoff_time = (now - datetime.timedelta(days=last_days))
+            cutoff_time = now - datetime.timedelta(days=last_days)
             for s in list(snapshot_dict.keys()):
                 if s < cutoff_time:
                     continue
                 if s not in to_keep:
                     to_keep.append(s)
-        r = re.findall('^last (\d+) snapshot', ritem)
+        r = re.findall(r"^last (\d+) snapshot", ritem)
         if len(r) > 0:
             last_snapshots = int(r[0])
             i = 0