Use logger instead of tqdm.write inside of tqdm

src/photomanager/actions/actions.py

@@ -2,13 +2,13 @@
 
 import logging
 import random
-import sys
 from collections.abc import Container, Iterable
 from os import PathLike
 from pathlib import Path
 from typing import Optional, TypedDict, Union
 
 from tqdm import tqdm
+from tqdm.contrib.logging import logging_redirect_tqdm
 
 from photomanager.actions import fileops
 from photomanager.database import Database, sizeof_fmt, tz_str_to_tzinfo
@@ -191,16 +191,17 @@ def verify(
         storage_type=storage_type,
     )
 
-    for photo in tqdm(stored_photos):
-        abs_store_path = str(destination / photo.sto)
-        if abs_store_path not in checksum_cache:
-            tqdm.write(f"Missing photo: {abs_store_path}", file=sys.stderr)
-            num_missing_photos += 1
-        elif checksum_cache[abs_store_path] == photo.chk:
-            num_correct_photos += 1
-        else:
-            tqdm.write(f"Incorrect checksum: {abs_store_path}", file=sys.stderr)
-            num_incorrect_photos += 1
+    with logging_redirect_tqdm():
+        for photo in tqdm(stored_photos):
+            abs_store_path = str(destination / photo.sto)
+            if abs_store_path not in checksum_cache:
+                logger.warning(f"Missing photo: {abs_store_path}")
+                num_missing_photos += 1
+            elif checksum_cache[abs_store_path] == photo.chk:
+                num_correct_photos += 1
+            else:
+                logger.warning(f"Incorrect checksum: {abs_store_path}")
+                num_incorrect_photos += 1
 
     logger.info(
         f"Checked "

src/photomanager/actions/fileops.py

@@ -4,7 +4,6 @@
 import re
 import shutil
 import stat
-import sys
 import traceback
 from collections.abc import Collection, Iterable
 from datetime import tzinfo
@@ -14,6 +13,7 @@
 
 import click
 from tqdm import tqdm
+from tqdm.contrib.logging import logging_redirect_tqdm
 
 from photomanager.database import sizeof_fmt
 from photomanager.hasher import DEFAULT_HASH_ALGO, AsyncFileHasher, HashAlgorithm
@@ -136,24 +136,23 @@ def index_photos(
     photos: list[Optional[PhotoFile]] = []
     exiftool = ExifTool()
     exiftool.start()
-    for current_file in tqdm(files_normalized):
-        if logger.isEnabledFor(logging.DEBUG):
-            tqdm.write(f"Indexing {current_file}", file=sys.stderr)
-        try:
-            pf = PhotoFile.from_file_cached(
-                current_file,
-                checksum_cache=checksum_cache,
-                datetime_cache=datetime_cache,
-                algorithm=hash_algorithm,
-                tz_default=tz_default,
-                priority=priority,
-            )
-            photos.append(pf)
-        except Exception:
-            tqdm.write(f"Error indexing {current_file}", file=sys.stderr)
-            tb_str = "".join(traceback.format_exc())
-            tqdm.write(tb_str, file=sys.stderr)
-            photos.append(None)
+    with logging_redirect_tqdm():
+        for current_file in tqdm(files_normalized):
+            logger.debug(f"Indexing {current_file}")
+            try:
+                pf = PhotoFile.from_file_cached(
+                    current_file,
+                    checksum_cache=checksum_cache,
+                    datetime_cache=datetime_cache,
+                    algorithm=hash_algorithm,
+                    tz_default=tz_default,
+                    priority=priority,
+                )
+                photos.append(pf)
+            except Exception:
+                tb_str = "".join(traceback.format_exc())
+                logger.error(f"Error indexing {current_file}\n{tb_str}")
+                photos.append(None)
     exiftool.terminate()
     return photos
 
@@ -182,39 +181,35 @@ def copy_photos(
         f"{'Would copy' if dry_run else 'Copying'} {len(photos)} items, "
         f"estimated size: {sizeof_fmt(estimated_copy_size)}"
     )
-    p_bar = tqdm(
-        total=estimated_copy_size, unit="B", unit_scale=True, unit_divisor=1024
-    )
-    for photo, rel_store_path in photos:
-        if rel_store_path is None:
-            abs_store_path = directory / photo.sto
-        else:
-            abs_store_path = directory / rel_store_path
-        if logger.isEnabledFor(logging.DEBUG):
-            tqdm.write(
+    with logging_redirect_tqdm():
+        p_bar = tqdm(
+            total=estimated_copy_size, unit="B", unit_scale=True, unit_divisor=1024
+        )
+        for photo, rel_store_path in photos:
+            if rel_store_path is None:
+                abs_store_path = directory / photo.sto
+            else:
+                abs_store_path = directory / rel_store_path
+            logger.debug(
                 f"{'Would copy' if dry_run else 'Copying'}: {photo.src} "
-                f"to {abs_store_path}",
-                file=sys.stderr,
+                f"to {abs_store_path}"
             )
-        try:
-            if not dry_run:
-                makedirs(abs_store_path.parent, exist_ok=True)
-                shutil.copy2(photo.src, abs_store_path)
-                chmod(abs_store_path, stat.S_IRUSR | stat.S_IRGRP | stat.S_IROTH)
-                if rel_store_path is not None:
-                    photo.sto = rel_store_path
-        except Exception:
-            tqdm.write(
-                f"Error copying {photo.src} to {abs_store_path}", file=sys.stderr
-            )
-            tb_str = "".join(traceback.format_exc())
-            tqdm.write(tb_str, file=sys.stderr)
-            num_error_photos += 1
-        else:
-            num_copied_photos += 1
-            total_copy_size += photo.fsz
-        p_bar.update(photo.fsz)
-    p_bar.close()
+            try:
+                if not dry_run:
+                    makedirs(abs_store_path.parent, exist_ok=True)
+                    shutil.copy2(photo.src, abs_store_path)
+                    chmod(abs_store_path, stat.S_IRUSR | stat.S_IRGRP | stat.S_IROTH)
+                    if rel_store_path is not None:
+                        photo.sto = rel_store_path
+            except Exception:
+                tb_str = "".join(traceback.format_exc())
+                logger.error(f"Error copying {photo.src} to {abs_store_path}\n{tb_str}")
+                num_error_photos += 1
+            else:
+                num_copied_photos += 1
+                total_copy_size += photo.fsz
+            p_bar.update(photo.fsz)
+        p_bar.close()
     return num_copied_photos, total_copy_size, num_error_photos
 
 
@@ -234,22 +229,20 @@ def remove_photos(
     logger = logging.getLogger(__name__)
     directory = Path(directory).expanduser().resolve()
     num_removed_photos = num_missing_photos = 0
-    for photo in tqdm(photos):
-        abs_store_path = directory / photo.sto
-        if abs_store_path.exists():
-            if logger.isEnabledFor(logging.DEBUG):
-                tqdm.write(
-                    f"{'Would remove' if dry_run else 'Removing'}: {abs_store_path}",
-                    file=sys.stderr,
+    with logging_redirect_tqdm():
+        for photo in tqdm(photos):
+            abs_store_path = directory / photo.sto
+            if abs_store_path.exists():
+                logger.debug(
+                    f"{'Would remove' if dry_run else 'Removing'}: {abs_store_path}"
                 )
-            if not dry_run:
-                remove(abs_store_path)
-                photo.sto = ""
-            num_removed_photos += 1
-        else:
-            if logger.isEnabledFor(logging.DEBUG):
-                tqdm.write(f"Missing photo: {abs_store_path}", file=sys.stderr)
-            num_missing_photos += 1
+                if not dry_run:
+                    remove(abs_store_path)
+                    photo.sto = ""
+                num_removed_photos += 1
+            else:
+                logger.debug(f"Missing photo: {abs_store_path}")
+                num_missing_photos += 1
     return num_removed_photos, num_missing_photos
 
 

src/photomanager/actions/migrate.py

@@ -7,6 +7,7 @@
 from typing import Optional, Union
 
 from tqdm import tqdm
+from tqdm.contrib.logging import logging_redirect_tqdm
 
 from photomanager.database import Database, sizeof_fmt
 from photomanager.hasher import HashAlgorithm, file_checksum
@@ -39,30 +40,32 @@ def make_hash_map(
         hash_map = {}
     old_algo = database.hash_algorithm
     print(f"Converting {old_algo} to {new_algo}")
+    logger = logging.getLogger()
     num_correct_photos = (
         num_incorrect_photos
     ) = num_missing_photos = num_skipped_photos = 0
     all_photos = [photo for photos in database.photo_db.values() for photo in photos]
-    for photo in tqdm(all_photos):
-        if photo.chk in hash_map:
-            num_skipped_photos += 1
-        elif exists(photo.src):
-            if photo.chk == file_checksum(photo.src, old_algo):
-                hash_map[photo.chk] = file_checksum(photo.src, new_algo)
-                num_correct_photos += 1
-            else:
-                tqdm.write(f"Incorrect checksum: {photo.src}")
-                hash_map[photo.chk] = photo.chk + f":{old_algo}"
-                num_incorrect_photos += 1
-        elif destination:
-            sto_path = Path(destination).expanduser().resolve() / photo.sto
-            if exists(sto_path) and photo.chk == file_checksum(sto_path, old_algo):
-                hash_map[photo.chk] = file_checksum(sto_path, new_algo)
-                num_correct_photos += 1
+    with logging_redirect_tqdm():
+        for photo in tqdm(all_photos):
+            if photo.chk in hash_map:
+                num_skipped_photos += 1
+            elif exists(photo.src):
+                if photo.chk == file_checksum(photo.src, old_algo):
+                    hash_map[photo.chk] = file_checksum(photo.src, new_algo)
+                    num_correct_photos += 1
+                else:
+                    logger.warning(f"Incorrect checksum: {photo.src}")
+                    hash_map[photo.chk] = photo.chk + f":{old_algo}"
+                    num_incorrect_photos += 1
+            elif destination:
+                sto_path = Path(destination).expanduser().resolve() / photo.sto
+                if exists(sto_path) and photo.chk == file_checksum(sto_path, old_algo):
+                    hash_map[photo.chk] = file_checksum(sto_path, new_algo)
+                    num_correct_photos += 1
+                else:
+                    num_missing_photos += 1
             else:
                 num_missing_photos += 1
-        else:
-            num_missing_photos += 1
 
     print(f"Mapped {num_correct_photos} items")
     if num_skipped_photos:
@@ -159,34 +162,34 @@ def update_stored_filename_hashes(
     print(f"Total file size: {sizeof_fmt(total_file_size)}")
     logger = logging.getLogger()
     file_map = {}
-    for photo in tqdm(stored_photos):
-        abs_store_path = destination / photo.sto
-        new_store_path = f"{photo.sto[:32]}{photo.chk[:7]}{photo.sto[39:]}"
-        new_abs_store_path = destination / new_store_path
-        if new_abs_store_path.exists():
-            num_skipped_photos += 1
-        elif not abs_store_path.exists():
-            tqdm.write(f"Missing photo: {abs_store_path}")
-            num_missing_photos += 1
-        elif photo.sto[32:39] == photo.chk[:7]:
-            num_skipped_photos += 1
-        elif (
-            not verify
-            or file_checksum(abs_store_path, database.hash_algorithm) == photo.chk
-        ):
-            if logger.isEnabledFor(logging.DEBUG):
-                tqdm.write(
+    with logging_redirect_tqdm():
+        for photo in tqdm(stored_photos):
+            abs_store_path = destination / photo.sto
+            new_store_path = f"{photo.sto[:32]}{photo.chk[:7]}{photo.sto[39:]}"
+            new_abs_store_path = destination / new_store_path
+            if new_abs_store_path.exists():
+                num_skipped_photos += 1
+            elif not abs_store_path.exists():
+                logger.warning(f"Missing photo: {abs_store_path}")
+                num_missing_photos += 1
+            elif photo.sto[32:39] == photo.chk[:7]:
+                num_skipped_photos += 1
+            elif (
+                not verify
+                or file_checksum(abs_store_path, database.hash_algorithm) == photo.chk
+            ):
+                logger.debug(
                     f"{'Will move' if dry_run else 'Moving'} {abs_store_path} "
                     f"to {new_abs_store_path}"
                 )
-            file_map[str(abs_store_path)] = str(new_abs_store_path)
-            if not dry_run:
-                rename(abs_store_path, new_abs_store_path)
-                photo.sto = new_store_path
-            num_correct_photos += 1
-        else:
-            tqdm.write(f"Incorrect checksum: {abs_store_path}")
-            num_incorrect_photos += 1
+                file_map[str(abs_store_path)] = str(new_abs_store_path)
+                if not dry_run:
+                    rename(abs_store_path, new_abs_store_path)
+                    photo.sto = new_store_path
+                num_correct_photos += 1
+            else:
+                logger.warning(f"Incorrect checksum: {abs_store_path}")
+                num_incorrect_photos += 1
     print(f"{'Would move' if dry_run else 'Moved'} {num_correct_photos} items")
     if num_skipped_photos:
         print(f"Skipped {num_skipped_photos} items")

tests/unit_tests/test_actions.py

@@ -336,6 +336,9 @@ def test_verify_random_sample(tmpdir, caplog):
     assert result["num_correct_photos"] == 0
     assert result["num_incorrect_photos"] == 0
     assert result["num_missing_photos"] == 1
+    assert any("Missing photo" in m for m in caplog.messages)
+    assert not any("Incorrect checksum" in m for m in caplog.messages)
+    caplog.clear()
 
     Path(tmpdir / "store" / "a.jpg").touch()
     Path(tmpdir / "store" / "b.jpg").touch()
@@ -351,3 +354,6 @@ def test_verify_random_sample(tmpdir, caplog):
     assert result["num_correct_photos"] == 0
     assert result["num_incorrect_photos"] == 2
     assert result["num_missing_photos"] == 0
+    assert not any("Missing photo" in m for m in caplog.messages)
+    assert any("Incorrect checksum" in m for m in caplog.messages)
+    caplog.clear()