diff --git a/.env.example b/.env.example index 537fb80..6d6553e 100644 --- a/.env.example +++ b/.env.example @@ -24,3 +24,6 @@ FSLOGIX_GROUP_SID=S-1-5-21-1111111111-2222222222-3333333333-513 # BACKUP_RETENTION_WEEKLY=2 # BACKUP_RETENTION_MONTHLY=2 # BACKUP_RETENTION_YEARLY=1 +# BACKUP_LOG_FILE=/var/log/backup.log +# BACKUP_PROGRESS=auto +# BACKUP_PROGRESS_INTERVAL_SECONDS=10 diff --git a/README.md b/README.md index 1dd81aa..4fd8492 100644 --- a/README.md +++ b/README.md @@ -121,6 +121,9 @@ Kerberos requires close time alignment. - optional `BACKUP_RETENTION_WEEKLY` (default `2`) - optional `BACKUP_RETENTION_MONTHLY` (default `2`) - optional `BACKUP_RETENTION_YEARLY` (default `1`) + - optional `BACKUP_LOG_FILE` (default `/var/log/backup.log`) + - optional `BACKUP_PROGRESS` (`auto`, `always`, or `never`; default `auto`) + - optional `BACKUP_PROGRESS_INTERVAL_SECONDS` (default `10`) Optional: - `SAMBA_HOSTNAME` (defaults to `adsambafsrv`) @@ -198,6 +201,9 @@ Kerberos requires close time alignment. - `BACKUP_RETENTION_MONTHLY=2` - `BACKUP_RETENTION_WEEKLY=2` - `BACKUP_RETENTION_DAILY=3` +- The backup script writes directly to `BACKUP_LOG_FILE` (default: `/var/log/backup.log`). Cron does not redirect backup output into the logfile. +- Upload progress is logged per file every `BACKUP_PROGRESS_INTERVAL_SECONDS` seconds and again when a file reaches 100%. +- `BACKUP_PROGRESS=auto` shows an interactive progress bar only for TTY/manual runs. Use `always` to force it or `never` to suppress the bar. File progress is still logged. - Retention logic: - daily: newest N snapshots - weekly: newest N snapshots created on week start (Monday) @@ -220,6 +226,9 @@ Kerberos requires close time alignment. BACKUP_RETENTION_WEEKLY=2 BACKUP_RETENTION_MONTHLY=2 BACKUP_RETENTION_YEARLY=1 + BACKUP_LOG_FILE=/var/log/backup.log + BACKUP_PROGRESS=auto + BACKUP_PROGRESS_INTERVAL_SECONDS=10 ``` ## Useful Commands diff --git a/app/backup_to_destination.py b/app/backup_to_destination.py index 745a892..fd22480 100644 --- a/app/backup_to_destination.py +++ b/app/backup_to_destination.py @@ -7,13 +7,33 @@ import re import subprocess import sys import tempfile +import time from dataclasses import dataclass -from typing import Dict, List, Optional, Set, Tuple +from typing import Callable, Dict, List, Optional, Set, TextIO, Tuple from urllib.parse import SplitResult, unquote, urlsplit LOCK_PATH = "/state/backup.lock" +DEFAULT_BACKUP_LOG_FILE = "/var/log/backup.log" +DEFAULT_PROGRESS_MODE = "auto" +DEFAULT_PROGRESS_INTERVAL_SECONDS = 10 +PROGRESS_BAR_WIDTH = 28 +MAX_CAPTURED_OUTPUT_LINES = 50 +MAX_CAPTURED_OUTPUT_RECORD_LENGTH = 1000 SNAPSHOT_NAME_RE = re.compile(r"^\d{8}T\d{6}Z$") +ANSI_ESCAPE_RE = re.compile(r"\x1b\[[0-?]*[ -/]*[@-~]") +RCLONE_FILE_PROGRESS_RE = re.compile( + r"^\s*\*\s+(?P.+?):\s+(?P\d+(?:\.\d+)?)%\s*(?P.*)$" +) +RSYNC_FILE_PROGRESS_RE = re.compile( + r"^\s*[\d,.]+[A-Za-z]?\s+(?P\d+(?:\.\d+)?)%\s+(?P.+)$" +) +RSYNC_IGNORED_RECORD_PREFIXES = ( + "sending incremental file list", + "receiving incremental file list", + "sent ", + "total size is ", +) BACKUP_SOURCES: List[Tuple[str, str]] = [ ("/data/private", "data/private"), @@ -67,8 +87,73 @@ class Snapshot: timestamp: dt.datetime -def log(message: str) -> None: - print(f"[backup] {message}", flush=True) +@dataclass(frozen=True) +class FileProgress: + file_path: str + percent: float + detail: str + + +class BackupLogger: + def __init__( + self, + *, + console_stream: TextIO = sys.stdout, + error_stream: TextIO = sys.stderr, + ): + self.console_stream = console_stream + self.error_stream = error_stream + self.log_path: Optional[str] = None + self._handle: Optional[TextIO] = None + + def configure(self, log_path: str) -> None: + self.close() + self.log_path = log_path + if not log_path: + return + + log_dir = os.path.dirname(log_path) + try: + if log_dir: + os.makedirs(log_dir, exist_ok=True) + self._handle = open(log_path, "a", encoding="utf-8") + except OSError as exc: + self._handle = None + print( + f"[backup] WARNING: unable to open log file {log_path}: {exc}", + file=self.error_stream, + flush=True, + ) + + def close(self) -> None: + if self._handle is None: + return + self._handle.close() + self._handle = None + + def log(self, message: str, *, console: bool = True) -> None: + line = f"[backup] {message}" + if console: + print(line, file=self.console_stream, flush=True) + if self._handle is not None: + timestamp = dt.datetime.now(dt.timezone.utc).isoformat(timespec="seconds") + self._handle.write(f"{timestamp} {line}\n") + self._handle.flush() + + +LOGGER = BackupLogger() + + +def configure_logging() -> None: + LOGGER.configure(os.getenv("BACKUP_LOG_FILE", DEFAULT_BACKUP_LOG_FILE).strip()) + + +def close_logging() -> None: + LOGGER.close() + + +def log(message: str, *, console: bool = True) -> None: + LOGGER.log(message, console=console) def run_command( @@ -91,6 +176,256 @@ def run_command( return result +def parse_progress_mode() -> str: + raw_value = os.getenv("BACKUP_PROGRESS", DEFAULT_PROGRESS_MODE).strip().lower() + if raw_value in {"auto", "always", "never"}: + return raw_value + log(f"Invalid BACKUP_PROGRESS='{raw_value}', using default {DEFAULT_PROGRESS_MODE}") + return DEFAULT_PROGRESS_MODE + + +def should_show_progress_bar(mode: str, stream: TextIO = sys.stderr) -> bool: + if mode == "always": + return True + if mode == "never": + return False + return bool(stream.isatty()) + + +def format_percent(percent: float) -> str: + if percent.is_integer(): + return str(int(percent)) + return f"{percent:.1f}".rstrip("0").rstrip(".") + + +def clamp_percent(percent: float) -> float: + return max(0.0, min(100.0, percent)) + + +def shorten_middle(value: str, max_length: int) -> str: + if len(value) <= max_length: + return value + if max_length <= 3: + return value[:max_length] + left = (max_length - 3) // 2 + right = max_length - 3 - left + return f"{value[:left]}...{value[-right:]}" + + +def clean_output_record(record: str) -> str: + return ANSI_ESCAPE_RE.sub("", record).strip() + + +def truncate_output_record(record: str) -> str: + if len(record) <= MAX_CAPTURED_OUTPUT_RECORD_LENGTH: + return record + return f"{record[:MAX_CAPTURED_OUTPUT_RECORD_LENGTH]}..." + + +def parse_rclone_progress_record(record: str) -> Optional[FileProgress]: + match = RCLONE_FILE_PROGRESS_RE.match(record) + if not match: + return None + return FileProgress( + file_path=match.group("file").strip(), + percent=clamp_percent(float(match.group("percent"))), + detail=match.group("detail").strip(), + ) + + +def rsync_file_candidate(record: str) -> Optional[str]: + stripped = record.strip() + if not stripped: + return None + lower = stripped.lower() + if any(lower.startswith(prefix) for prefix in RSYNC_IGNORED_RECORD_PREFIXES): + return None + if lower.startswith("deleting "): + return None + if stripped.endswith("/"): + return None + if RSYNC_FILE_PROGRESS_RE.match(stripped): + return None + return stripped + + +def parse_rsync_progress_record( + record: str, current_file: Optional[str] +) -> Optional[FileProgress]: + if not current_file: + return None + match = RSYNC_FILE_PROGRESS_RE.match(record) + if not match: + return None + return FileProgress( + file_path=current_file, + percent=clamp_percent(float(match.group("percent"))), + detail=match.group("detail").strip(), + ) + + +class OutputRecordSplitter: + def __init__(self) -> None: + self._buffer = "" + + def feed(self, chunk: str) -> List[str]: + records: List[str] = [] + for char in chunk: + if char in {"\r", "\n"}: + record = clean_output_record(self._buffer) + self._buffer = "" + if record: + records.append(record) + continue + self._buffer += char + return records + + def close(self) -> List[str]: + record = clean_output_record(self._buffer) + self._buffer = "" + if not record: + return [] + return [record] + + +class SyncProgressReporter: + def __init__( + self, + backend_name: str, + source_path: str, + destination_path: str, + *, + interval_seconds: int, + interactive: bool, + stream: TextIO = sys.stderr, + now: Callable[[], float] = time.monotonic, + log_func: Callable[..., None] = log, + ): + self.backend_name = backend_name + self.source_path = source_path + self.destination_path = destination_path + self.interval_seconds = interval_seconds + self.interactive = interactive + self.stream = stream + self.now = now + self.log_func = log_func + self.current_rsync_file: Optional[str] = None + self._last_log_at: Dict[str, float] = {} + self._last_logged_percent: Dict[str, float] = {} + self._last_bar_length = 0 + + def observe(self, record: str) -> None: + progress: Optional[FileProgress] + if self.backend_name == "rclone": + progress = parse_rclone_progress_record(record) + else: + progress = parse_rsync_progress_record(record, self.current_rsync_file) + if progress is None: + candidate = rsync_file_candidate(record) + if candidate is not None: + self.current_rsync_file = candidate + return + + if progress is None: + return + self._render_bar(progress) + self._log_progress(progress) + + def finish(self) -> None: + if not self.interactive or self._last_bar_length == 0: + return + self.stream.write("\r" + (" " * self._last_bar_length) + "\r") + self.stream.flush() + self._last_bar_length = 0 + + def _log_progress(self, progress: FileProgress) -> None: + now = self.now() + key = progress.file_path + last_log_at = self._last_log_at.get(key) + last_logged_percent = self._last_logged_percent.get(key) + is_final = progress.percent >= 100.0 + if ( + last_log_at is not None + and now - last_log_at < self.interval_seconds + and not (is_final and last_logged_percent != 100.0) + ): + return + + detail = f" ({progress.detail})" if progress.detail else "" + self.log_func( + "Upload progress " + f"{self.source_path} -> {self.destination_path}: " + f"{progress.file_path} {format_percent(progress.percent)}%{detail}", + console=not self.interactive, + ) + self._last_log_at[key] = now + self._last_logged_percent[key] = progress.percent + + def _render_bar(self, progress: FileProgress) -> None: + if not self.interactive: + return + filled = int(PROGRESS_BAR_WIDTH * (progress.percent / 100.0)) + bar = "#" * filled + "-" * (PROGRESS_BAR_WIDTH - filled) + file_path = shorten_middle(progress.file_path, 44) + source_path = shorten_middle(self.source_path, 24) + line = ( + f"[backup] {source_path}: {file_path} " + f"[{bar}] {format_percent(progress.percent)}%" + ) + if len(line) >= self._last_bar_length: + padding = "" + else: + padding = " " * (self._last_bar_length - len(line)) + self.stream.write(f"\r{line}{padding}") + self.stream.flush() + self._last_bar_length = len(line) + + +def run_streaming_command( + command: List[str], + *, + progress: SyncProgressReporter, + env: Optional[Dict[str, str]] = None, +) -> subprocess.CompletedProcess: + process = subprocess.Popen( + command, + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, + text=True, + bufsize=1, + env=env, + ) + splitter = OutputRecordSplitter() + captured_records: List[str] = [] + + try: + if process.stdout is not None: + while True: + chunk = process.stdout.read(1) + if chunk == "": + if process.poll() is not None: + break + continue + for record in splitter.feed(chunk): + captured_records.append(truncate_output_record(record)) + captured_records = captured_records[-MAX_CAPTURED_OUTPUT_LINES:] + progress.observe(record) + + for record in splitter.close(): + captured_records.append(truncate_output_record(record)) + captured_records = captured_records[-MAX_CAPTURED_OUTPUT_LINES:] + progress.observe(record) + + returncode = process.wait() + finally: + progress.finish() + + stdout = "\n".join(captured_records) + if returncode != 0: + output = stdout.strip() or f"exit code {returncode}" + raise RuntimeError(f"Command failed ({command[0]}): {output}") + return subprocess.CompletedProcess(command, returncode, stdout=stdout, stderr="") + def parse_destination(raw_url: str) -> Destination: parts = urlsplit(raw_url) scheme = parts.scheme.lower() @@ -399,16 +734,38 @@ class RcloneBackend: return join_path(self._snapshots_root(), snapshot_name) def sync_source( - self, snapshot_name: str, source_path: str, destination_path: str + self, + snapshot_name: str, + source_path: str, + destination_path: str, + *, + progress_interval_seconds: int, + interactive_progress: bool, ) -> None: remote_path = join_path(self._snapshot_root(snapshot_name), destination_path) - self._run( + progress = SyncProgressReporter( + "rclone", + source_path, + destination_path, + interval_seconds=progress_interval_seconds, + interactive=interactive_progress, + ) + run_streaming_command( [ + "rclone", "sync", f"{source_path}/", f"backup:{remote_path}", "--create-empty-src-dirs", - ] + "--progress", + "--stats", + f"{progress_interval_seconds}s", + "--log-level", + "INFO", + "--config", + self.config_path, + ], + progress=progress, ) def write_marker(self, snapshot_name: str) -> None: @@ -494,14 +851,36 @@ class RsyncBackend: return f"{self.remote_base}/{trimmed}" def sync_source( - self, snapshot_name: str, source_path: str, destination_path: str + self, + snapshot_name: str, + source_path: str, + destination_path: str, + *, + progress_interval_seconds: int, + interactive_progress: bool, ) -> None: target = self._remote_path( join_path(f"snapshots/{snapshot_name}", destination_path) ) - run_command( - ["rsync", "-a", "--delete", f"{source_path}/", f"{target}/"], + progress = SyncProgressReporter( + "rsync", + source_path, + destination_path, + interval_seconds=progress_interval_seconds, + interactive=interactive_progress, + ) + run_streaming_command( + [ + "rsync", + "-a", + "--delete", + "--progress", + "--outbuf=L", + f"{source_path}/", + f"{target}/", + ], env=self.command_env, + progress=progress, ) def write_marker(self, snapshot_name: str) -> None: @@ -621,6 +1000,15 @@ def run_backup() -> int: log("No backup sources are available, skipping backup") return 0 + progress_interval_seconds = parse_int_env( + "BACKUP_PROGRESS_INTERVAL_SECONDS", + DEFAULT_PROGRESS_INTERVAL_SECONDS, + minimum=1, + maximum=None, + ) + progress_mode = parse_progress_mode() + interactive_progress = should_show_progress_bar(progress_mode) + destination = parse_destination(destination_url) backend = build_backend(destination) try: @@ -632,7 +1020,13 @@ def run_backup() -> int: for source_path, destination_path in sources: log(f"Syncing {source_path}") - backend.sync_source(snapshot_name, source_path, destination_path) + backend.sync_source( + snapshot_name, + source_path, + destination_path, + progress_interval_seconds=progress_interval_seconds, + interactive_progress=interactive_progress, + ) backend.write_marker(snapshot_name) @@ -670,20 +1064,24 @@ def with_lock() -> int: def main() -> int: - backup_hour = parse_int_env( - "BACKUP_START_HOUR", - DEFAULT_BACKUP_START_HOUR, - minimum=0, - maximum=23, - ) - if backup_hour != DEFAULT_BACKUP_START_HOUR: - log(f"Configured backup start hour is {backup_hour}:00") - + configure_logging() try: - return with_lock() - except Exception as exc: # pylint: disable=broad-except - log(f"ERROR: {exc}") - return 1 + backup_hour = parse_int_env( + "BACKUP_START_HOUR", + DEFAULT_BACKUP_START_HOUR, + minimum=0, + maximum=23, + ) + if backup_hour != DEFAULT_BACKUP_START_HOUR: + log(f"Configured backup start hour is {backup_hour}:00") + + try: + return with_lock() + except Exception as exc: # pylint: disable=broad-except + log(f"ERROR: {exc}") + return 1 + finally: + close_logging() if __name__ == "__main__": diff --git a/app/init.sh b/app/init.sh index 643bae0..af86725 100755 --- a/app/init.sh +++ b/app/init.sh @@ -214,6 +214,15 @@ write_runtime_env_file() { if [[ -n "${BACKUP_RETENTION_YEARLY:-}" ]]; then printf 'export BACKUP_RETENTION_YEARLY=%q\n' "$BACKUP_RETENTION_YEARLY" fi + if [[ -n "${BACKUP_LOG_FILE:-}" ]]; then + printf 'export BACKUP_LOG_FILE=%q\n' "$BACKUP_LOG_FILE" + fi + if [[ -n "${BACKUP_PROGRESS:-}" ]]; then + printf 'export BACKUP_PROGRESS=%q\n' "$BACKUP_PROGRESS" + fi + if [[ -n "${BACKUP_PROGRESS_INTERVAL_SECONDS:-}" ]]; then + printf 'export BACKUP_PROGRESS_INTERVAL_SECONDS=%q\n' "$BACKUP_PROGRESS_INTERVAL_SECONDS" + fi if [[ -n "${JOIN_USER:-}" ]]; then printf 'export JOIN_USER=%q\n' "$JOIN_USER" fi @@ -288,7 +297,7 @@ EOF if [[ -n "${BACKUP_DESTINATION:-}" ]]; then cat >> /etc/cron.d/reconcile-shares <> /var/log/backup.log 2>&1 +0 ${BACKUP_START_HOUR} * * * root source /app/runtime.env && /usr/bin/python3 /app/backup_to_destination.py EOF fi diff --git a/setup b/setup index 1976393..20d7cc8 100755 --- a/setup +++ b/setup @@ -325,6 +325,9 @@ NETBIOS_NAME=${netbios_name} # BACKUP_RETENTION_WEEKLY=2 # BACKUP_RETENTION_MONTHLY=2 # BACKUP_RETENTION_YEARLY=1 +# BACKUP_LOG_FILE=/var/log/backup.log +# BACKUP_PROGRESS=auto +# BACKUP_PROGRESS_INTERVAL_SECONDS=10 EOF chmod 600 "$ENV_FILE" diff --git a/tests/test_backup_to_destination.py b/tests/test_backup_to_destination.py new file mode 100644 index 0000000..4cc57ea --- /dev/null +++ b/tests/test_backup_to_destination.py @@ -0,0 +1,162 @@ +import io +import os +import tempfile +import unittest +from unittest import mock + +from app import backup_to_destination as backup + + +class BackupLoggerTests(unittest.TestCase): + def test_logger_writes_console_and_timestamped_file(self): + console = io.StringIO() + errors = io.StringIO() + with tempfile.TemporaryDirectory() as tmpdir: + log_path = os.path.join(tmpdir, "backup.log") + logger = backup.BackupLogger(console_stream=console, error_stream=errors) + logger.configure(log_path) + logger.log("hello") + logger.close() + + self.assertEqual(console.getvalue(), "[backup] hello\n") + self.assertEqual(errors.getvalue(), "") + with open(log_path, encoding="utf-8") as handle: + contents = handle.read() + + self.assertRegex( + contents, + r"^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\+00:00 \[backup\] hello\n$", + ) + + +class ProgressConfigTests(unittest.TestCase): + def test_parse_progress_mode_accepts_known_values(self): + with mock.patch.dict(os.environ, {"BACKUP_PROGRESS": "ALWAYS"}): + self.assertEqual(backup.parse_progress_mode(), "always") + + def test_parse_progress_mode_defaults_invalid_values(self): + with mock.patch.dict(os.environ, {"BACKUP_PROGRESS": "loud"}): + with mock.patch.object(backup, "log") as log: + self.assertEqual(backup.parse_progress_mode(), "auto") + log.assert_called_once() + + def test_should_show_progress_bar_honors_mode_and_tty(self): + class Stream: + def __init__(self, is_tty): + self.is_tty = is_tty + + def isatty(self): + return self.is_tty + + self.assertTrue(backup.should_show_progress_bar("always", Stream(False))) + self.assertFalse(backup.should_show_progress_bar("never", Stream(True))) + self.assertTrue(backup.should_show_progress_bar("auto", Stream(True))) + self.assertFalse(backup.should_show_progress_bar("auto", Stream(False))) + + +class ProgressParsingTests(unittest.TestCase): + def test_splitter_handles_carriage_returns_newlines_and_ansi(self): + splitter = backup.OutputRecordSplitter() + + self.assertEqual(splitter.feed("\x1b[2Kone\rtwo\n\nthree"), ["one", "two"]) + self.assertEqual(splitter.close(), ["three"]) + + def test_parse_rclone_file_progress(self): + progress = backup.parse_rclone_progress_record( + " * data/private/file.txt: 42.5% /10Mi, 2Mi/s, ETA 4s" + ) + + self.assertEqual(progress.file_path, "data/private/file.txt") + self.assertEqual(progress.percent, 42.5) + self.assertEqual(progress.detail, "/10Mi, 2Mi/s, ETA 4s") + + def test_parse_rsync_file_progress_uses_current_file(self): + progress = backup.parse_rsync_progress_record( + " 1,024 50% 1.00MB/s 0:00:01", "dir/file.bin" + ) + + self.assertEqual(progress.file_path, "dir/file.bin") + self.assertEqual(progress.percent, 50.0) + self.assertEqual(progress.detail, "1.00MB/s 0:00:01") + + def test_reporter_throttles_progress_but_logs_final_event(self): + clock = [0.0] + logs = [] + reporter = backup.SyncProgressReporter( + "rsync", + "/src", + "data/private", + interval_seconds=10, + interactive=True, + stream=io.StringIO(), + now=lambda: clock[0], + log_func=lambda message, console=True: logs.append((message, console)), + ) + + reporter.observe("dir/file.bin") + reporter.observe(" 10 10% 1.00MB/s 0:00:09") + clock[0] = 5.0 + reporter.observe(" 20 20% 1.00MB/s 0:00:08") + clock[0] = 10.0 + reporter.observe(" 30 30% 1.00MB/s 0:00:07") + clock[0] = 11.0 + reporter.observe(" 100 100% 1.00MB/s 0:00:00") + + self.assertEqual(len(logs), 3) + self.assertIn("dir/file.bin 10%", logs[0][0]) + self.assertIn("dir/file.bin 30%", logs[1][0]) + self.assertIn("dir/file.bin 100%", logs[2][0]) + self.assertEqual([console for _, console in logs], [False, False, False]) + + +class BackendProgressCommandTests(unittest.TestCase): + def test_rclone_sync_uses_progress_flags(self): + destination = backup.parse_destination("sftp://user@example.com/backups") + backend = backup.RcloneBackend(destination) + try: + with mock.patch.object(backup, "run_streaming_command") as run_streaming: + backend.sync_source( + "20260101T000000Z", + "/src", + "data/private", + progress_interval_seconds=7, + interactive_progress=False, + ) + + command = run_streaming.call_args.args[0] + self.assertIn("--progress", command) + self.assertIn("--stats", command) + self.assertIn("7s", command) + self.assertIn("--log-level", command) + self.assertIn("INFO", command) + self.assertIn("--config", command) + self.assertEqual( + run_streaming.call_args.kwargs["progress"].backend_name, "rclone" + ) + finally: + backend.close() + + def test_rsync_sync_uses_progress_flags(self): + destination = backup.parse_destination("rsync://user@example.com/module/path") + backend = backup.RsyncBackend(destination) + + with mock.patch.object(backup, "run_streaming_command") as run_streaming: + backend.sync_source( + "20260101T000000Z", + "/src", + "data/private", + progress_interval_seconds=7, + interactive_progress=False, + ) + + command = run_streaming.call_args.args[0] + self.assertIn("--progress", command) + self.assertIn("--outbuf=L", command) + self.assertEqual( + run_streaming.call_args.kwargs["progress"].backend_name, "rsync" + ) + self.assertIs(run_streaming.call_args.kwargs["env"], backend.command_env) + + +if __name__ == "__main__": + unittest.main()