rewrite for robustness.

cmps_hevc_crf18.py

@@ -1,72 +1,32 @@
 #!/usr/bin/python3
 import argparse
 import subprocess
-import re
-import logging
-from shutil import get_terminal_size
-from sys import argv, stdout
+
+from sys import argv
 from pathlib import Path
 
-try:
-    import colorlog
-    fmt_arr = [
-        "%(cyan)s%(asctime)s.%(msecs)03d%(reset)s",
-        "%(log_color)s%(levelname)-7s%(reset)s",
-        "%(blue)s%(message)s%(reset)s",
-    ]
-    fmt = colorlog.ColoredFormatter(
-        " | ".join(fmt_arr),
-        datefmt="%Y-%m-%d %H:%M:%S"
-    )
-except ImportError:
-    fmt = logging.Formatter(
-        "%(asctime)s.%(msecs)03d | %(levelname)-7s | %(message)s",
-        datefmt="%Y-%m-%d %H:%M:%S"
-    )
+from logger import get_logger
+from progress import get_progress_bar, is_tty
+
+COMPRESS_OPTIONS = [
+    "-c:v", "libx265", "-crf", "18", "-preset", "medium",
+    "-c:a", "copy",
+    "-tag:v", "hvc1",
+]
 
-fmt.default_msec_format = "%s.%03d"
-handler = logging.StreamHandler()
-handler.setFormatter(fmt)
-logger = logging.getLogger('example')
-logger.addHandler(handler)
-logger.setLevel('DEBUG')
 itsme = Path(argv[0]).name
+logger = get_logger(itsme)
 
 
-class RawProgressBar:
-    def __init__(self, total=100, unit='%'):
-        self.total = total
-        self.unit = unit
-        self.current = 0
-        self.cols = get_terminal_size((40, 20)).columns
-
-    def update(self, delta):
-        self.current += delta
-        self._print_bar()
-
-    def _print_bar(self):
-        cur = min(self.current, self.total)
-        pct = min(cur / self.total if self.total > 0 else 0, 1.0)
-        pct_str = f"{pct * 100:3.1f}%"
-        rate_str = f"{cur:.2f}/{self.total:.2f}({self.unit})"
-        fixed_len = len(pct_str) + len(rate_str) + 10
-        bar_width = max(self.cols - fixed_len, 10)
-        filled_len = int(bar_width * pct)
-        bar = '>' * filled_len + '-' * (bar_width - filled_len)
-        output = f"\r {pct_str} [{bar}] {rate_str}"
-        stdout.write(output)
-        stdout.flush()
-
-    def close(self):
-        stdout.write('\n')
-        stdout.flush()
-
-
-try:
-    from tqdm import tqdm
-    ProgressBar = tqdm
-except ImportError:
-    ProgressBar = RawProgressBar
+def check_ffmpeg():
+    try:
+        subprocess.run(['ffmpeg', '-version'],
+                       capture_output=True, check=True)
+        subprocess.run(['ffprobe', '-version'],
+                       capture_output=True, check=True)
+    except (subprocess.CalledProcessError, FileNotFoundError):
+        logger.error("ffmpeg not found or not working. Please install ffmpeg.")
+        raise SystemExit(1)
 
 
 def get_duration(file_path: Path):
@@ -75,57 +35,72 @@ def get_duration(file_path: Path):
         '-of', 'default=noprint_wrappers=1:nokey=1', str(file_path)
     ]
     result = subprocess.run(
-        cmd,
-        stdout=subprocess.PIPE,
-        stderr=subprocess.STDOUT,
-        text=True
-    )
-    return float(result.stdout.strip())
+        cmd, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True)
+    try:
+        dur = float(result.stdout.strip())
+        if dur <= 0:
+            raise ValueError(f"Invalid duration: {dur}")
+        return dur
+    except (ValueError, TypeError) as e:
+        logger.error(f"Cannot determine duration of {file_path}: {e}")
+        raise
 
 
-def time_to_seconds(time_str):
-    h, m, s = map(float, time_str.split(':'))
-    return h * 3600 + m * 60 + s
+def read_progress(ostream_line, dur, pbar):
+    if not ostream_line.startswith("out_time_ms="):
+        return
+    try:
+        us = int(ostream_line.split('=')[1])
+        if us < 0:
+            return
+        secs = us / 1_000_000
+        if secs > dur * 1.1:  # Allow 10% overshoot
+            pbar.n = dur
+        else:
+            pbar.n = secs
+        pbar.refresh()
+    except (ValueError, OverflowError):
+        pass
 
 
 def hevc_encode(infile: Path, outfile: Path, progress: bool = True):
+    # too heavy bro.
     dur = get_duration(infile)
     cmd = [
-        "ffmpeg", "-y",
-        "-i", str(infile),
-        "-c:v", "libx265", "-crf", "18", "-preset", "medium",
-        "-c:a", "copy",
-        "-tag:v", "hvc1",
-        str(outfile)
+        "ffmpeg", "-y", "-i", str(infile),
+        "-progress", "pipe:1", "-nostats",
+        *COMPRESS_OPTIONS, str(outfile)
     ]
-    logger.info(f"Encoding {Path(infile).name} to HEVC CRF 18...")
     logger.debug(f"Duration: {dur:.2f} seconds")
     logger.debug(f"Command: {' '.join(cmd)}")
     proc = subprocess.Popen(
-        cmd,
-        stderr=subprocess.PIPE,
-        text=True,
-        encoding='utf-8'
-    )
-
-    pbar = ProgressBar(total=dur, unit='s') if progress else None
-    last_time = 0
+        cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE,
+        text=True, encoding='utf-8', bufsize=1)
+    progress = progress and is_tty()
+    pbar = None if not progress else get_progress_bar(
+        total=dur, unit='s',
+        bar_format='{l_bar}{bar}| {n:.2f}/{total:.2f}({unit})')
     try:
         while True:
-            line = proc.stderr.readline()
+            line = proc.stdout.readline()
             if not line and proc.poll() is not None:
                 break
             if not pbar:
                 continue
-            match = re.search(r"time=(\d{2}:\d{2}:\d{2}.\d{2})", line)
-            if match:
-                current_time = time_to_seconds(match.group(1))
-                pbar.update(current_time - last_time)
-                last_time = current_time
-    except KeyboardInterrupt:
-        logger.warning("SIGINT received, terminating ffmpeg ...")
-        proc.kill()
+            read_progress(line.strip(), dur, pbar)
         proc.wait()
+        if proc.returncode != 0:
+            raise subprocess.CalledProcessError(proc.returncode, cmd)
+    except (
+        KeyboardInterrupt,
+        subprocess.CalledProcessError
+    ) as e:
+        if proc.poll() is None:
+            proc.kill()
+            proc.wait()
+        logger.error(
+            f"Encoding failed with code {proc.returncode}:"
+            f" {e.__class__.__name__}")
         if outfile.exists():
             try:
                 outfile.unlink()
@@ -136,11 +111,6 @@ def hevc_encode(infile: Path, outfile: Path, progress: bool = True):
         if pbar:
             pbar.close()
 
-    if proc.returncode != 0:
-        # logger.error(proc.stdout.read())
-        # logger.error(proc.stderr.readlines())
-        raise subprocess.CalledProcessError(proc.returncode, cmd)
-
 
 def build_file_list(srcdir, extensions):
     exts = {ext.lower().lstrip('.') for ext in extensions}
@@ -177,7 +147,8 @@ def parse_args():
     parser.add_argument('-r', '--rm-original', dest='remove_original',
                         action='store_true',
                         help='Remove original after encoding')
-    parser.add_argument('-s', '--silent', dest='silent', action='store_true',
+    parser.add_argument('-s', '--silent', dest='silent',
+                        action='store_true',
                         help='Keep silent (no progress bar)')
     parser.add_argument('files', nargs='*',
                         help='Input files (with no -d/--dir)')
@@ -193,6 +164,7 @@ def parse_args():
 
 
 def main():
+    check_ffmpeg()
     args = parse_args()
 
     if args.srcdir:
@@ -205,21 +177,32 @@ def main():
     if not files:
         raise SystemExit(errmsg)
 
-    for infile in files:
-        # print(f"Processing: {infile}")
+    for idx, infile in enumerate(files, 1):
+        logger.info(f"[{idx}/{len(files)}] {infile.name}")
+
         outfile = make_output_path(infile, args.outdir, args.srcdir)
         outfile.parent.mkdir(parents=True, exist_ok=True)
-        hevc_encode(infile, outfile, not args.silent)
+        try:
+            outfile.touch(0o644)
+            hevc_encode(infile, outfile, not args.silent)
+        except (OSError, PermissionError) as e:
+            logger.error(f"Job failed: {e}")
+            raise
         final_out = outfile.with_name(
             outfile.name.replace(".hevc.mp4", ".mp4"))
-        if args.remove_original:
-            logger.debug(f"Remove original: {infile}")
-            infile.unlink()
-        elif final_out.resolve() == infile.resolve():
-            logger.warning(f"Filename conflict: {infile} <= {final_out}")
-            infile.rename(infile.with_suffix('.bak.mp4'))
+        if final_out.resolve() == infile.resolve():
+            logger.warning(
+                f"Filename conflict!\n  i: {infile}\n  o: {final_out}")
+            if not args.remove_original:
+                logger.debug("renaming original to avoid conflict.")
+                infile.rename(infile.with_stem(infile.stem + '.bak'))
+            outfile.replace(final_out)
+        else:
+            outfile.replace(final_out)
+            if args.remove_original:
+                logger.debug(f"Remove original: {infile}")
+                infile.unlink()
         logger.debug(f"Output file: {final_out}")
-        outfile.replace(final_out)
 
 
 if __name__ == '__main__':