diff --git a/bot/modules/media_loader/ytdlp.py b/bot/modules/media_loader/ytdlp.py index ec7f291..6462a0d 100644 --- a/bot/modules/media_loader/ytdlp.py +++ b/bot/modules/media_loader/ytdlp.py @@ -442,24 +442,30 @@ async def download_media( original_stderr = sys.stderr error_filter = None + logger.info(f"Starting yt-dlp download for URL: {url}") + try: # Redirect stderr to filter non-critical errors error_filter = YtDlpErrorFilter(original_stderr) sys.stderr = error_filter + logger.info(f"Extracting info for URL: {url}") with yt_dlp.YoutubeDL(ydl_opts) as ydl: # Check for cancellation before start if cancel_event and cancel_event.is_set(): raise KeyboardInterrupt("Download cancelled") # Get video information + logger.info(f"Extracting video info for: {url}") info = ydl.extract_info(url, download=False) + logger.info(f"Video info extracted: title={info.get('title', 'N/A')[:50]}, duration={info.get('duration', 'N/A')}") # Check for cancellation after getting info if cancel_event and cancel_event.is_set(): raise KeyboardInterrupt("Download cancelled") # Download (progress hook will be called from this thread) + logger.info(f"Starting download for: {url}") # Note: Some postprocessors may show errors (like FixupM3u8 with aspect ratio), # but the video file is still downloaded correctly try: diff --git a/bot/modules/message_handler/commands.py b/bot/modules/message_handler/commands.py index 4f0da70..558d8d0 100644 --- a/bot/modules/message_handler/commands.py +++ b/bot/modules/message_handler/commands.py @@ -726,8 +726,10 @@ async def url_handler(client: Client, message: Message): return # Add to queue (with duplicate URL check) AFTER saving to database + logger.info(f"Adding task {task_id} to queue (URL: {url[:50]}...)") success = await task_queue.add_task(task, check_duplicate_url=True) if not success: + logger.warning(f"Failed to add task {task_id} to queue (duplicate or error)") # If failed to add to queue, remove from database try: async with get_async_session_local()() as session: @@ -745,7 +747,11 @@ async def url_handler(client: Client, message: Message): # Start executor if not already started if not task_executor._running: + logger.info(f"Starting task executor for task {task_id}") await task_executor.start() + logger.info(f"Task executor started, workers should begin processing tasks") + else: + logger.debug(f"Task executor already running, task {task_id} will be processed by existing workers") # Send initial status message and save message_id for updates from bot.modules.task_scheduler.executor import set_task_message diff --git a/bot/modules/task_scheduler/executor.py b/bot/modules/task_scheduler/executor.py index 209a26c..e1389b8 100644 --- a/bot/modules/task_scheduler/executor.py +++ b/bot/modules/task_scheduler/executor.py @@ -196,6 +196,8 @@ class TaskExecutor: await asyncio.sleep(0.5) continue + logger.info(f"Worker {name} got task {task.id} from queue (URL: {task.url[:50] if task.url else 'N/A'}...)") + # Check for cancellation before starting processing current_task = await task_queue.get_task_by_id(task.id) if current_task and current_task.status == TaskStatus.CANCELLED: @@ -204,13 +206,14 @@ class TaskExecutor: # Update status await task_queue.update_task_status(task.id, TaskStatus.PROCESSING) - - logger.info(f"Worker {name} processing task {task.id}") + logger.info(f"Worker {name} processing task {task.id} (status: PROCESSING)") # Execute task (doesn't block other workers and message processing) # Each task executes independently await self._execute_task(task) + logger.info(f"Worker {name} completed task {task.id}") + except asyncio.CancelledError: logger.info(f"Worker {name} stopped") break @@ -281,6 +284,8 @@ class TaskExecutor: async def _download_with_ytdlp(self, task: Task): """Download via yt-dlp""" + logger.info(f"Starting download for task {task.id}: {task.url}") + # Get cancellation event for this task cancel_event = task_queue.get_cancel_event(task.id) @@ -296,7 +301,9 @@ class TaskExecutor: from bot.modules.media_loader.ytdlp import get_media_info from shared.config import settings + logger.info(f"Getting media info for task {task.id}...") media_info = await get_media_info(task.url, cookies_file=settings.COOKIES_FILE) + logger.info(f"Media info retrieved for task {task.id}: title={media_info.get('title') if media_info else 'N/A'}") if media_info: # Check duration max_duration = settings.max_duration_minutes_int