From c5cfe497586e33dff4abd4e8341bdfca161bb38e Mon Sep 17 00:00:00 2001 From: Fuxino Date: Mon, 2 Nov 2026 19:54:11 +0100 Subject: [PATCH] Show elapsed time as (h:)mm:ss and add it to the notification Replace the timing decorator with a start time kept by Backup.run(), so the final notification can report how long the backup took. --- simple_backup/simple_backup.py | 44 ++++++++++++++-------------------- tests/test_local.py | 19 +++++++++++++++ 2 files changed, 37 insertions(+), 26 deletions(-) diff --git a/simple_backup/simple_backup.py b/simple_backup/simple_backup.py index 1fc001e..eeac9ac 100755 --- a/simple_backup/simple_backup.py +++ b/simple_backup/simple_backup.py @@ -25,9 +25,8 @@ import shlex import sys import warnings from collections import deque -from collections.abc import Callable, Iterator +from collections.abc import Iterator from datetime import datetime -from functools import wraps from getpass import GetPassWarning, getpass from glob import glob from logging import StreamHandler @@ -35,7 +34,7 @@ from shutil import get_terminal_size, rmtree, which from subprocess import PIPE, STDOUT, Popen from tempfile import mkstemp from timeit import default_timer -from typing import Any, ParamSpec, TypedDict, TypeVar +from typing import Any, TypedDict try: import paramiko @@ -69,9 +68,6 @@ if journal: j_handler.setFormatter(j_format) logger.addHandler(j_handler) -P = ParamSpec('P') -R = TypeVar('R') - # Seconds to wait for the TCP connection to the SSH server SSH_TIMEOUT = 15 @@ -80,25 +76,15 @@ PROGRESS_RE = re.compile(r'\s*(\S+)\s+\d+%\s+\S+\s+\d+:\d\d:\d\d(?:\s+\(xfr#\d+, PROGRESS_BAR_WIDTH = 30 -def timing(func: Callable[P, R]) -> Callable[P, R]: - """Decorator to measure execution time of a function +def _format_duration(seconds: float) -> str: + """Format seconds as mm:ss, or h:mm:ss from one hour""" - Parameters: - func: Function to decorate - """ - @wraps(func) - def wrapper(*args: P.args, **kwargs: P.kwargs) -> R: - start = default_timer() + s = round(seconds) - value = func(*args, **kwargs) + if s >= 3600: + return f'{s // 3600}:{s // 60 % 60:02d}:{s % 60:02d}' - end = default_timer() - - logger.info('Elapsed time: %.3f seconds', end - start) - - return value - - return wrapper + return f'{s // 60:02d}:{s % 60:02d}' class MyFormatter(argparse.RawTextHelpFormatter, argparse.ArgumentDefaultsHelpFormatter): @@ -233,6 +219,7 @@ class Backup: # Passed to sshpass through rsync's environment only self._password: str | None = None self._removed_count = 0 + self._start_time = 0.0 def check_params(self, homedir: str = '') -> int: """Check if parameters for the backup are valid""" @@ -669,14 +656,19 @@ class Backup: 'Rsync error (return code %d) - Check rsync(1) for details', returncode) # Function to read configuration file - @timing def run(self) -> int: """Perform the backup""" + self._start_time = default_timer() + try: return self._run() finally: self._remove_temp_files() + logger.info('Elapsed time: %s', self._elapsed()) + + def _elapsed(self) -> str: + return _format_duration(default_timer() - self._start_time) def close(self) -> None: """Close the SSH connection, if open""" @@ -831,14 +823,14 @@ class Backup: logger.error( 'Some errors occurred while performing the backup') - _notify( - 'Some errors occurred while performing the backup. Check log for details') + _notify(f'Some errors occurred while performing the backup (elapsed time {self._elapsed()}). ' + 'Check log for details') return 4 logger.info('Backup completed') - _notify('Backup completed') + _notify(f'Backup completed in {self._elapsed()}') return 0 diff --git a/tests/test_local.py b/tests/test_local.py index e4627e1..39a7c75 100644 --- a/tests/test_local.py +++ b/tests/test_local.py @@ -88,6 +88,18 @@ class TestRsync: assert 'Backup completed' in caplog.text assert 'rsync: sent' in caplog.text + def test_elapsed_time(self, src: Path, out: Path, monkeypatch: pytest.MonkeyPatch, + caplog: pytest.LogCaptureFixture) -> None: + notifications: list[str] = [] + monkeypatch.setattr(sb, '_notify', notifications.append) + # Start, then the notification and the log line + monkeypatch.setattr(sb, 'default_timer', iter([0.0, 863.187, 863.2]).__next__) + + assert run_backup(out, [str(src)]) == 0 + + assert notifications[-1] == 'Backup completed in 14:23' + assert 'Elapsed time: 14:23' in caplog.text + def test_hard_links(self, src: Path, out: Path) -> None: assert run_backup(out, [str(src)]) == 0 (src / 'changed.txt').write_text('second') @@ -231,6 +243,13 @@ class TestReadRecords: assert list(sb._read_records(stream)) == ['file', '', 'namé', '�'] +@pytest.mark.parametrize(('seconds', 'text'), [ + (0.4, '00:00'), (59.6, '01:00'), (863.187, '14:23'), (3599.4, '59:59'), (3600, '1:00:00'), (37230, '10:20:30'), +]) +def test_format_duration(seconds: float, text: str) -> None: + assert sb._format_duration(seconds) == text + + class TestProgressBar: @pytest.fixture(autouse=True) def terminal(self, monkeypatch: pytest.MonkeyPatch) -> None: