try to differentiate yt-dlp logs for each download.
This commit is contained in:
ArabCoders
parent
d94f004eed
commit
1b57e41e1b
2 changed files with 51 additions and 27 deletions
1
.vscode/settings.json
vendored
1
.vscode/settings.json
vendored
|
|
@ -21,6 +21,7 @@
|
|||
"finaldir",
|
||||
"getpid",
|
||||
"httpx",
|
||||
"levelno",
|
||||
"libcurl",
|
||||
"libx",
|
||||
"matroska",
|
||||
|
|
|
|||
|
|
@ -3,6 +3,7 @@ import hashlib
|
|||
import logging
|
||||
import multiprocessing
|
||||
import os
|
||||
import re
|
||||
import shutil
|
||||
import time
|
||||
from email.utils import formatdate
|
||||
|
|
@ -16,7 +17,22 @@ from .ffprobe import ffprobe
|
|||
from .ItemDTO import ItemDTO
|
||||
from .YTDLPOpts import YTDLPOpts
|
||||
|
||||
LOG = logging.getLogger("download")
|
||||
|
||||
class DebugPreProcessor(logging.Filter):
|
||||
def filter(self, record: logging.LogRecord):
|
||||
if record.levelno != logging.DEBUG:
|
||||
return True
|
||||
|
||||
if record.__dict__.get("processed", None):
|
||||
return True
|
||||
|
||||
logging.getLogger(record.name).log(
|
||||
level=logging.DEBUG if record.msg.startswith("") else logging.INFO,
|
||||
msg=re.sub(r"^\[.*\] ", "", record.msg),
|
||||
extra={"processed": True},
|
||||
)
|
||||
|
||||
return False
|
||||
|
||||
|
||||
class Download:
|
||||
|
|
@ -89,6 +105,9 @@ class Download:
|
|||
self.is_live = bool(info.is_live) or info.live_in is not None
|
||||
self.is_manifestless = "is_manifestless" in self.info.options and self.info.options["is_manifestless"] is True
|
||||
self.info_dict = info_dict
|
||||
self.logger = logging.getLogger(f"Download.{info.id if info.id else info._id}")
|
||||
self.ytdlp_logger = logging.getLogger(f"ytdlp.{info.id if info.id else info._id}")
|
||||
self.ytdlp_logger.addFilter(DebugPreProcessor())
|
||||
|
||||
def _progress_hook(self, data: dict):
|
||||
dataDict = {k: v for k, v in data.items() if k in self._ytdlp_fields}
|
||||
|
|
@ -105,7 +124,7 @@ class Download:
|
|||
return
|
||||
|
||||
if self.debug:
|
||||
LOG.debug(f"Postprocessor hook: {data}")
|
||||
self.logger.debug(f"Postprocessor hook: {data}")
|
||||
|
||||
if "__finaldir" in data["info_dict"]:
|
||||
filename = os.path.join(data["info_dict"]["__finaldir"], os.path.basename(data["info_dict"]["filepath"]))
|
||||
|
|
@ -154,12 +173,14 @@ class Download:
|
|||
if self.info.cookies:
|
||||
try:
|
||||
cookie_file = os.path.join(self.temp_path, f"cookie_{self.info._id}.txt")
|
||||
LOG.debug(f"Creating cookie file for '{self.info.id}: {self.info.title}' - '{cookie_file}'.")
|
||||
self.logger.debug(
|
||||
f"Creating cookie file for '{self.info.id}: {self.info.title}' - '{cookie_file}'."
|
||||
)
|
||||
with open(cookie_file, "w") as f:
|
||||
f.write(self.info.cookies)
|
||||
params["cookiefile"] = f.name
|
||||
except ValueError as e:
|
||||
LOG.error(f"Failed to create cookie file for '{self.info.id}: {self.info.title}'. '{e!s}'.")
|
||||
self.logger.error(f"Failed to create cookie file for '{self.info.id}: {self.info.title}'. '{e!s}'.")
|
||||
|
||||
if self.is_live or self.is_manifestless:
|
||||
hasDeletedOptions = False
|
||||
|
|
@ -171,37 +192,39 @@ class Download:
|
|||
deletedOpts.append(opt)
|
||||
|
||||
if hasDeletedOptions:
|
||||
LOG.warning(
|
||||
self.logger.warning(
|
||||
f"Live stream detected for '{self.info.title}', The following opts '{deletedOpts=}' have been deleted which are known to cause issues with live stream and post stream manifestless mode."
|
||||
)
|
||||
|
||||
LOG.info(
|
||||
self.logger.info(
|
||||
f'Task id="{self.info.id}" PID="{os.getpid()}" title="{self.info.title}" preset="{self.preset}" started.'
|
||||
)
|
||||
|
||||
LOG.debug("Params before passing to yt-dlp.", extra=params)
|
||||
self.logger.debug("Params before passing to yt-dlp.", extra=params)
|
||||
|
||||
if "impersonate" in params:
|
||||
from yt_dlp.networking.impersonate import ImpersonateTarget
|
||||
|
||||
params["impersonate"] = ImpersonateTarget.from_str(params["impersonate"])
|
||||
|
||||
params["logger"] = self.ytdlp_logger
|
||||
|
||||
cls = yt_dlp.YoutubeDL(params=params)
|
||||
|
||||
if isinstance(self.info_dict, dict) and len(self.info_dict) > 1:
|
||||
LOG.debug(f"Downloading '{self.info.url}' using pre-info.")
|
||||
self.logger.debug(f"Downloading '{self.info.url}' using pre-info.")
|
||||
cls.process_ie_result(self.info_dict, download=True)
|
||||
ret = cls._download_retcode
|
||||
else:
|
||||
LOG.debug(f"Downloading using url: {self.info.url}")
|
||||
self.logger.debug(f"Downloading using url: {self.info.url}")
|
||||
ret = cls.download([self.info.url])
|
||||
|
||||
self.status_queue.put({"id": self.id, "status": "finished" if ret == 0 else "error"})
|
||||
except Exception as exc:
|
||||
LOG.exception(exc)
|
||||
self.logger.exception(exc)
|
||||
self.status_queue.put({"id": self.id, "status": "error", "msg": str(exc), "error": str(exc)})
|
||||
|
||||
LOG.info(f'Task id="{self.info.id}" PID="{os.getpid()}" title="{self.info.title}" completed.')
|
||||
self.logger.info(f'Task id="{self.info.id}" PID="{os.getpid()}" title="{self.info.title}" completed.')
|
||||
|
||||
async def start(self, emitter: Emitter):
|
||||
self.emitter = emitter
|
||||
|
|
@ -244,28 +267,28 @@ class Download:
|
|||
self.cancel_in_progress = True
|
||||
procId = self.proc.ident
|
||||
|
||||
LOG.info(f"Closing PID='{procId}' download process.")
|
||||
self.logger.info(f"Closing PID='{procId}' download process.")
|
||||
|
||||
try:
|
||||
try:
|
||||
if "update_task" in self.__dict__ and self.update_task.done() is False:
|
||||
self.update_task.cancel()
|
||||
except Exception as e:
|
||||
LOG.error(f"Failed to close status queue: '{procId}'. {e}")
|
||||
self.logger.error(f"Failed to close status queue: '{procId}'. {e}")
|
||||
|
||||
self.kill()
|
||||
|
||||
loop = asyncio.get_running_loop()
|
||||
|
||||
if self.proc.is_alive():
|
||||
LOG.debug(f"Waiting for PID='{procId}' to close.")
|
||||
self.logger.debug(f"Waiting for PID='{procId}' to close.")
|
||||
await loop.run_in_executor(None, self.proc.join)
|
||||
LOG.debug(f"PID='{procId}' closed.")
|
||||
self.logger.debug(f"PID='{procId}' closed.")
|
||||
|
||||
if self.status_queue:
|
||||
LOG.debug(f"Closing status queue for PID='{procId}'.")
|
||||
self.logger.debug(f"Closing status queue for PID='{procId}'.")
|
||||
self.status_queue.put(Terminator())
|
||||
LOG.debug(f"Closed status queue for PID='{procId}'.")
|
||||
self.logger.debug(f"Closed status queue for PID='{procId}'.")
|
||||
|
||||
if self.proc:
|
||||
self.proc.close()
|
||||
|
|
@ -273,11 +296,11 @@ class Download:
|
|||
|
||||
self.delete_temp()
|
||||
|
||||
LOG.debug(f"Closed PID='{procId}' download process.")
|
||||
self.logger.debug(f"Closed PID='{procId}' download process.")
|
||||
|
||||
return True
|
||||
except Exception as e:
|
||||
LOG.error(f"Failed to close process: '{procId}'. {e}")
|
||||
self.logger.error(f"Failed to close process: '{procId}'. {e}")
|
||||
|
||||
return False
|
||||
|
||||
|
|
@ -295,11 +318,11 @@ class Download:
|
|||
return False
|
||||
|
||||
try:
|
||||
LOG.info(f"Killing download process: '{self.proc.ident}'.")
|
||||
self.logger.info(f"Killing download process: '{self.proc.ident}'.")
|
||||
self.proc.kill()
|
||||
return True
|
||||
except Exception as e:
|
||||
LOG.error(f"Failed to kill process: '{self.proc.ident}'. {e}")
|
||||
self.logger.error(f"Failed to kill process: '{self.proc.ident}'. {e}")
|
||||
|
||||
return False
|
||||
|
||||
|
|
@ -308,7 +331,7 @@ class Download:
|
|||
return
|
||||
|
||||
if "finished" != self.info.status and self.is_live:
|
||||
LOG.warning(
|
||||
self.logger.warning(
|
||||
f"Keeping live temp folder '{self.temp_path}', as the reported status is not finished '{self.info.status}'."
|
||||
)
|
||||
return
|
||||
|
|
@ -317,12 +340,12 @@ class Download:
|
|||
return
|
||||
|
||||
if self.temp_path == self.temp_dir:
|
||||
LOG.warning(
|
||||
self.logger.warning(
|
||||
f"Attempted to delete video temp folder: {self.temp_path}, but it is the same as main temp folder."
|
||||
)
|
||||
return
|
||||
|
||||
LOG.info(f"Deleting Temp folder '{self.temp_path}'.")
|
||||
self.logger.info(f"Deleting Temp folder '{self.temp_path}'.")
|
||||
shutil.rmtree(self.temp_path, ignore_errors=True)
|
||||
|
||||
async def progress_update(self):
|
||||
|
|
@ -343,7 +366,7 @@ class Download:
|
|||
continue
|
||||
|
||||
if self.debug:
|
||||
LOG.debug(f"Status Update: {self.info._id=} {status=}")
|
||||
self.logger.debug(f"Status Update: {self.info._id=} {status=}")
|
||||
|
||||
if isinstance(status, str):
|
||||
asyncio.create_task(self.emitter.updated(dl=self.info), name=f"emitter-u-{self.id}")
|
||||
|
|
@ -400,7 +423,7 @@ class Download:
|
|||
except Exception as e:
|
||||
self.info.extras["is_video"] = True
|
||||
self.info.extras["is_audio"] = True
|
||||
LOG.exception(e)
|
||||
LOG.error(f"Failed to ffprobe: {status.get}. {e}")
|
||||
self.logger.exception(e)
|
||||
self.logger.error(f"Failed to ffprobe: {status.get}. {e}")
|
||||
|
||||
asyncio.create_task(self.emitter.updated(dl=self.info), name=f"emitter-u-{self.id}")
|
||||
|
|
|
|||
Loading…
Reference in a new issue