feat(tasks): add detailed logging to upload_with_rclone task functions

Co-authored-by: christianlouis <361235+christianlouis@users.noreply.github.com>

app/tasks/upload_with_rclone.py

@@ -7,12 +7,13 @@ import subprocess
 from app.celery_app import celery
 from app.config import settings
 from app.tasks.retry_config import BaseTaskWithRetry
+from app.utils import log_task_progress
 
 logger = logging.getLogger(__name__)
 
 
-@celery.task(base=BaseTaskWithRetry)
+@celery.task(base=BaseTaskWithRetry, bind=True)
-def upload_with_rclone(file_path: str, destination: str):
+def upload_with_rclone(self, file_path: str, destination: str):
     """
     Uploads a file using rclone to the specified destination.
 
@@ -21,12 +22,16 @@ def upload_with_rclone(file_path: str, destination: str):
         destination: Rclone destination in format "remote:path/to/folder"
                      e.g. "gdrive:Uploads" or "dropbox:Documents/Uploads"
     """
+    task_id = self.request.id
+
     if not os.path.exists(file_path):
         raise FileNotFoundError(f"File not found: {file_path}")
 
     # Extract filename
     filename = os.path.basename(file_path)
 
+    log_task_progress(task_id, "upload_with_rclone", "in_progress", f"Uploading {filename} to {destination}")
+
     # Validate destination format to prevent command injection
     if ":" not in destination:
         raise ValueError(f"Invalid destination format: {destination}. Expected format: remote:path")
@@ -43,9 +48,11 @@ def upload_with_rclone(file_path: str, destination: str):
     rclone_config_path = os.path.join(settings.workdir, "rclone.conf")
     if not os.path.exists(rclone_config_path):
         error_msg = f"Rclone configuration not found at {rclone_config_path}"
-        logger.error(error_msg)
+        logger.error(f"[{task_id}] {error_msg}")
         raise ValueError(error_msg)
 
+    log_task_progress(task_id, "validate_rclone", "success", f"Validated rclone config for {remote}")
+
     try:
         # Ensure the remote path exists (create folders if needed)
         mkdir_cmd = ["rclone", "mkdir", "--config", rclone_config_path, destination]
@@ -55,6 +62,8 @@ def upload_with_rclone(file_path: str, destination: str):
         # Construct the upload command
         upload_cmd = ["rclone", "copy", "--config", rclone_config_path, file_path, destination, "--progress"]
 
+        log_task_progress(task_id, "rclone_upload", "in_progress", f"Executing rclone copy to {destination}")
+
         # Execute the upload command
         result = subprocess.run(upload_cmd, check=True, capture_output=True, text=True)
 
@@ -66,44 +75,63 @@ def upload_with_rclone(file_path: str, destination: str):
                 link_result = subprocess.run(link_cmd, capture_output=True, text=True)
                 public_url = link_result.stdout.strip() if link_result.returncode == 0 else None
             except (subprocess.SubprocessError, OSError) as e:
-                logger.warning(f"Failed to get public link for {filename}: {str(e)}")
+                logger.warning(f"[{task_id}] Failed to get public link for {filename}: {str(e)}")
                 public_url = None
 
-            logger.info(f"Successfully uploaded {filename} to {destination}")
+            logger.info(f"[{task_id}] Successfully uploaded {filename} to {destination}")
+            log_task_progress(
+                task_id,
+                "upload_with_rclone",
+                "success",
+                f"Uploaded {filename} to {destination}",
+                detail=f"public_url={public_url}",
+            )
             return {"status": "Completed", "file": file_path, "destination": destination, "public_url": public_url}
         else:
             error_msg = f"Failed to upload {filename} to {destination}: {result.stderr}"
-            logger.error(error_msg)
+            logger.error(f"[{task_id}] {error_msg}")
             raise RuntimeError(error_msg)
 
     except subprocess.CalledProcessError as e:
         error_msg = f"Rclone error: {e.stderr.decode('utf-8') if hasattr(e.stderr, 'decode') else e.stderr}"
-        logger.error(error_msg)
+        logger.error(f"[{task_id}] {error_msg}")
+        log_task_progress(
+            task_id, "upload_with_rclone", "failure", f"Rclone command failed for {filename}", detail=error_msg
+        )
         raise RuntimeError(error_msg) from e
 
     except (OSError, ValueError) as e:
         error_msg = f"Error uploading {filename} to {destination}: {str(e)}"
-        logger.error(error_msg)
+        logger.error(f"[{task_id}] {error_msg}")
+        log_task_progress(
+            task_id, "upload_with_rclone", "failure", f"Upload failed for {filename}", detail=error_msg
+        )
         raise RuntimeError(error_msg) from e
 
 
-@celery.task(base=BaseTaskWithRetry)
+@celery.task(base=BaseTaskWithRetry, bind=True)
-def send_to_all_rclone_destinations(file_path: str):
+def send_to_all_rclone_destinations(self, file_path: str):
     """
     Uploads a file to all configured rclone destinations.
     Destinations are loaded from the rclone configuration file.
     """
+    task_id = self.request.id
+
     if not os.path.exists(file_path):
         raise FileNotFoundError(f"File not found: {file_path}")
 
     # Extract filename
     filename = os.path.basename(file_path)
 
+    log_task_progress(
+        task_id, "send_to_all_rclone_destinations", "in_progress", f"Queueing rclone uploads for {filename}"
+    )
+
     # Path to rclone config
     rclone_config_path = os.path.join(settings.workdir, "rclone.conf")
     if not os.path.exists(rclone_config_path):
         error_msg = f"Rclone configuration not found at {rclone_config_path}"
-        logger.error(error_msg)
+        logger.error(f"[{task_id}] {error_msg}")
         raise ValueError(error_msg)
 
     # Get list of configured destinations from rclone
@@ -133,17 +161,30 @@ def send_to_all_rclone_destinations(file_path: str):
                 if path and not path.endswith("/"):
                     full_destination += "/"
 
-                logger.info(f"Queueing {file_path} for upload to {full_destination}")
+                logger.info(f"[{task_id}] Queueing {file_path} for upload to {full_destination}")
                 task = upload_with_rclone.delay(file_path, full_destination)
                 results[f"rclone_{remote.rstrip(':')}_task_id"] = task.id
 
+            log_task_progress(
+                task_id,
+                "send_to_all_rclone_destinations",
+                "success",
+                f"Queued {len(results)} rclone upload(s)",
+            )
             return {"status": "Queued", "file_path": file_path, "tasks": results}
         else:
             error_msg = f"Failed to list rclone remotes: {result.stderr}"
-            logger.error(error_msg)
+            logger.error(f"[{task_id}] {error_msg}")
             raise RuntimeError(error_msg)
 
     except (subprocess.SubprocessError, OSError) as e:
         error_msg = f"Error setting up rclone uploads for {filename}: {str(e)}"
-        logger.error(error_msg)
+        logger.error(f"[{task_id}] {error_msg}")
+        log_task_progress(
+            task_id,
+            "send_to_all_rclone_destinations",
+            "failure",
+            f"Failed to set up rclone uploads for {filename}",
+            detail=error_msg,
+        )
         raise RuntimeError(error_msg) from e

tests/test_rclone_tasks.py

@@ -15,7 +15,8 @@ class TestUploadWithRclone:
         with pytest.raises(FileNotFoundError):
             upload_with_rclone("/nonexistent/file.pdf", "remote:path")
 
-    def test_raises_value_error_invalid_destination(self, tmp_path):
+    @patch("app.tasks.upload_with_rclone.log_task_progress")
+    def test_raises_value_error_invalid_destination(self, mock_log, tmp_path):
         """Test raises ValueError for invalid destination format."""
         test_file = tmp_path / "test.pdf"
         test_file.write_bytes(b"test")
@@ -23,7 +24,8 @@ class TestUploadWithRclone:
         with pytest.raises(ValueError, match="Invalid destination format"):
             upload_with_rclone(str(test_file), "invalid_destination")
 
-    def test_raises_value_error_invalid_remote_name(self, tmp_path):
+    @patch("app.tasks.upload_with_rclone.log_task_progress")
+    def test_raises_value_error_invalid_remote_name(self, mock_log, tmp_path):
         """Test raises ValueError for invalid remote name."""
         test_file = tmp_path / "test.pdf"
         test_file.write_bytes(b"test")
@@ -31,7 +33,8 @@ class TestUploadWithRclone:
         with pytest.raises(ValueError, match="Invalid remote name"):
             upload_with_rclone(str(test_file), ":path")
 
-    def test_raises_value_error_no_config(self, tmp_path):
+    @patch("app.tasks.upload_with_rclone.log_task_progress")
+    def test_raises_value_error_no_config(self, mock_log, tmp_path):
         """Test raises ValueError when rclone config not found."""
         test_file = tmp_path / "test.pdf"
         test_file.write_bytes(b"test")