improved logging.

This commit is contained in:
ArabCoders 2023-12-31 17:34:31 +03:00
parent 0297258405
commit ff7bd2fdeb
6 changed files with 37 additions and 33 deletions

View file

@ -20,6 +20,8 @@ import caribou
import sqlite3 import sqlite3
from aiocron import crontab from aiocron import crontab
log: logging.Logger = None
class Main: class Main:
config: Config = None config: Config = None
@ -30,52 +32,55 @@ class Main:
connection: sqlite3.Connection = None connection: sqlite3.Connection = None
dqueue: DownloadQueue = None dqueue: DownloadQueue = None
loop: asyncio.AbstractEventLoop = None loop: asyncio.AbstractEventLoop = None
logger: logging.Logger = None
def __init__(self): def __init__(self):
self.config = Config() self.config = Config()
self.config.version = APP_VERSION self.config.version = APP_VERSION
self.logger = logging.getLogger('main')
try: try:
if not os.path.exists(self.config.download_path): if not os.path.exists(self.config.download_path):
logging.info( self.logger.info(
f'Creating download folder at {self.config.download_path}') f'Creating download folder at {self.config.download_path}')
os.makedirs(self.config.download_path, exist_ok=True) os.makedirs(self.config.download_path, exist_ok=True)
except OSError as e: except OSError as e:
logging.error( self.logger.error(
f'Could not create download folder at {self.config.download_path}') f'Could not create download folder at {self.config.download_path}')
raise e raise e
try: try:
if not os.path.exists(self.config.temp_path): if not os.path.exists(self.config.temp_path):
logging.info( self.logger.info(
f'Creating temp folder at {self.config.temp_path}') f'Creating temp folder at {self.config.temp_path}')
os.makedirs(self.config.temp_path, exist_ok=True) os.makedirs(self.config.temp_path, exist_ok=True)
except OSError as e: except OSError as e:
logging.error( self.logger.error(
f'Could not create temp folder at {self.config.temp_path}') f'Could not create temp folder at {self.config.temp_path}')
raise e raise e
try: try:
if not os.path.exists(self.config.config_path): if not os.path.exists(self.config.config_path):
logging.info( self.logger.info(
f'Creating config folder at {self.config.config_path}') f'Creating config folder at {self.config.config_path}')
os.makedirs(self.config.config_path, exist_ok=True) os.makedirs(self.config.config_path, exist_ok=True)
except OSError as e: except OSError as e:
logging.error( self.logger.error(
f'Could not create config folder at {self.config.config_path}') f'Could not create config folder at {self.config.config_path}')
raise e raise e
try: try:
if not os.path.exists(self.config.db_file): if not os.path.exists(self.config.db_file):
logging.info( self.logger.info(
f'Creating database file at {self.config.db_file}') f'Creating database file at {self.config.db_file}')
with open(self.config.db_file, 'w') as _: with open(self.config.db_file, 'w') as _:
pass pass
except OSError as e: except OSError as e:
logging.error( self.logger.error(
f'Could not create database file at {self.config.db_file}') f'Could not create database file at {self.config.db_file}')
raise e raise e
caribou.upgrade(self.config.db_file, os.path.join(os.path.realpath(os.path.dirname(__file__)), 'migrations')) caribou.upgrade(self.config.db_file, os.path.join(
os.path.realpath(os.path.dirname(__file__)), 'migrations'))
self.loop = asyncio.get_event_loop() self.loop = asyncio.get_event_loop()
self.serializer = ObjectSerializer() self.serializer = ObjectSerializer()
@ -126,7 +131,7 @@ class Main:
def addTasks(self): def addTasks(self):
tasks_file: str = os.path.join(self.config.config_path, 'tasks.json') tasks_file: str = os.path.join(self.config.config_path, 'tasks.json')
if not os.path.exists(tasks_file): if not os.path.exists(tasks_file):
logging.info( self.logger.info(
f'No tasks file found at {tasks_file}. Skipping Tasks.') f'No tasks file found at {tasks_file}. Skipping Tasks.')
return return
@ -134,20 +139,20 @@ class Main:
with open(tasks_file, 'r') as f: with open(tasks_file, 'r') as f:
tasks = json.load(f) tasks = json.load(f)
except Exception as e: except Exception as e:
logging.error( self.logger.error(
f'Could not load tasks file [{tasks_file}]. Error message [{str(e)}]. Skipping Tasks.') f'Could not load tasks file [{tasks_file}]. Error message [{str(e)}]. Skipping Tasks.')
return return
for task in tasks: for task in tasks:
if not task.get('url'): if not task.get('url'):
logging.warning(f'Invalid task {task}.') self.logger.warning(f'Invalid task {task}.')
continue continue
cron_timer: str = task.get( cron_timer: str = task.get(
'timer', f'{random.randint(1,59)} */1 * * *') 'timer', f'{random.randint(1,59)} */1 * * *')
async def cron_runner(task: dict): async def cron_runner(task: dict):
logging.info( self.logger.info(
f'Running task [{task.get("name",task.get("url"))}] at [{datetime.now().strftime("%Y-%m-%d %H:%M:%S")}].') f'Running task [{task.get("name",task.get("url"))}] at [{datetime.now().strftime("%Y-%m-%d %H:%M:%S")}].')
await self.add( await self.add(
@ -160,7 +165,7 @@ class Main:
output_template=task.get('output_template') output_template=task.get('output_template')
) )
logging.info( self.logger.info(
f'Finished Running task [{task.get("name",task.get("url"))}] at [{datetime.now().strftime("%Y-%m-%d %H:%M:%S")}].') f'Finished Running task [{task.get("name",task.get("url"))}] at [{datetime.now().strftime("%Y-%m-%d %H:%M:%S")}].')
crontab( crontab(
@ -171,7 +176,7 @@ class Main:
loop=self.loop loop=self.loop
) )
logging.info( self.logger.info(
f'Added task to grab {task.get("name",task.get("url"))} content every [{cron_timer}].') f'Added task to grab {task.get("name",task.get("url"))} content every [{cron_timer}].')
def addRoutes(self): def addRoutes(self):

View file

@ -89,6 +89,8 @@ class Config:
format="%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s] %(message)s" format="%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s] %(message)s"
) )
log = logging.getLogger('config')
coloredlogs.install() coloredlogs.install()
if isinstance(self.ytdl_options, str): if isinstance(self.ytdl_options, str):
@ -96,14 +98,14 @@ class Config:
self.ytdl_options = json.loads(self.ytdl_options) self.ytdl_options = json.loads(self.ytdl_options)
assert isinstance(self.ytdl_options, dict) assert isinstance(self.ytdl_options, dict)
except (json.decoder.JSONDecodeError, AssertionError) as e: except (json.decoder.JSONDecodeError, AssertionError) as e:
logging.error(f'JSON error in "YTP_YTDL_OPTIONS": {e}') log.error(f'JSON error in "YTP_YTDL_OPTIONS": {e}')
sys.exit(1) sys.exit(1)
if self.ytdl_options_file: if self.ytdl_options_file:
logging.info( log.info(
f'Loading yt-dlp custom options from "{self.ytdl_options_file}"') f'Loading yt-dlp custom options from "{self.ytdl_options_file}"')
if not os.path.exists(self.ytdl_options_file): if not os.path.exists(self.ytdl_options_file):
logging.error( log.error(
f'"YTP_YTDL_OPTIONS_FILE" ENV points to non-existent file: "{self.ytdl_options_file}"') f'"YTP_YTDL_OPTIONS_FILE" ENV points to non-existent file: "{self.ytdl_options_file}"')
else: else:
try: try:
@ -112,12 +114,12 @@ class Config:
assert isinstance(opts, dict) assert isinstance(opts, dict)
self.ytdl_options.update(opts) self.ytdl_options.update(opts)
except (json.decoder.JSONDecodeError, AssertionError) as e: except (json.decoder.JSONDecodeError, AssertionError) as e:
logging.error( log.error(
f'JSON error in "{self.ytdl_options_file}": {e}') f'JSON error in "{self.ytdl_options_file}": {e}')
sys.exit(1) sys.exit(1)
if self.keep_archive: if self.keep_archive:
logging.info(f'keep archive: {self.keep_archive}') log.info(f'keep archive: {self.keep_archive}')
self.ytdl_options['download_archive'] = os.path.join( self.ytdl_options['download_archive'] = os.path.join(
self.config_path, 'archive.log') self.config_path, 'archive.log')

View file

@ -119,17 +119,17 @@ class Download:
try: try:
data = jsonCookie(json.loads(self.info.ytdlp_cookies)) data = jsonCookie(json.loads(self.info.ytdlp_cookies))
if not data: if not data:
logging.warning( log.warning(
f'The cookie string that was provided for {self.info.title} is empty or not in expected spec.') f'The cookie string that was provided for {self.info.title} is empty or not in expected spec.')
with open(os.path.join(self.tempPath, f'cookie_{self.info._id}.txt'), 'w') as f: with open(os.path.join(self.tempPath, f'cookie_{self.info._id}.txt'), 'w') as f:
f.write(data) f.write(data)
params['cookiefile'] = f.name params['cookiefile'] = f.name
except ValueError as e: except ValueError as e:
logging.error( log.error(
f'Invalid cookies: was provided for {self.info.title} - {str(e)}') f'Invalid cookies: was provided for {self.info.title} - {str(e)}')
logging.info( log.info(
f'Downloading {self.info._id=} {self.info.title=}... {params=}') f'Downloading {self.info._id=} {self.info.title=}... {params=}')
ret = yt_dlp.YoutubeDL(params=params).download([self.info.url]) ret = yt_dlp.YoutubeDL(params=params).download([self.info.url])
@ -144,7 +144,7 @@ class Download:
}) })
if self.tempPath and self.info._id and os.path.exists(self.tempPath): if self.tempPath and self.info._id and os.path.exists(self.tempPath):
logging.debug(f'Deleting Temp directory: {self.tempPath}') log.debug(f'Deleting Temp directory: {self.tempPath}')
shutil.rmtree(self.tempPath, ignore_errors=True) shutil.rmtree(self.tempPath, ignore_errors=True)
async def start(self, notifier: Notifier): async def start(self, notifier: Notifier):

View file

@ -100,20 +100,20 @@ class DownloadQueue:
return {'status': 'ok'} return {'status': 'ok'}
elif (etype == 'video' or etype.startswith('url')) and 'id' in entry and 'title' in entry: elif (etype == 'video' or etype.startswith('url')) and 'id' in entry and 'title' in entry:
logging.debug( log.debug(
f"entry: {entry.get('id', None)} - {entry.get('webpage_url', None)} - {entry.get('url', None) }") f"entry: {entry.get('id', None)} - {entry.get('webpage_url', None)} - {entry.get('url', None) }")
if self.done.exists(key=entry['id'], url=entry.get('webpage_url') or entry['url']): if self.done.exists(key=entry['id'], url=entry.get('webpage_url') or entry['url']):
item = self.done.get(key=entry['id'], url=entry.get( item = self.done.get(key=entry['id'], url=entry.get(
'webpage_url') or entry['url']) 'webpage_url') or entry['url'])
logging.debug( log.debug(
f'Item [{item.info.title}] already downloaded. Removing from history.') f'Item [{item.info.title}] already downloaded. Removing from history.')
await self.clear([item.info._id]) await self.clear([item.info._id])
if self.queue.exists(key=entry['id'], url=entry.get('webpage_url') or entry['url']): if self.queue.exists(key=entry['id'], url=entry.get('webpage_url') or entry['url']):
logging.info( log.info(
f'Item [{item.info.title}] already in download queue') f'Item [{item.info.title}] already in download queue')
return {'status': 'error', 'msg': 'Link already queued for downloading.'} return {'status': 'error', 'msg': 'Link already queued for downloading.'}
@ -215,7 +215,7 @@ class DownloadQueue:
'status': 'error', 'status': 'error',
'msg': 'No metadata, most likely video has been downloaded before.' if self.config.keep_archive else 'Unable to extract info check logs.' 'msg': 'No metadata, most likely video has been downloaded before.' if self.config.keep_archive else 'Unable to extract info check logs.'
} }
logging.debug(f'entry: extract info says: {entry}') log.debug(f'entry: extract info says: {entry}')
except yt_dlp.utils.YoutubeDLError as exc: except yt_dlp.utils.YoutubeDLError as exc:
return {'status': 'error', 'msg': str(exc)} return {'status': 'error', 'msg': str(exc)}

View file

@ -1,5 +1,3 @@
import json
import logging
import math import math
import os import os
from urllib.parse import quote from urllib.parse import quote

View file

@ -1,13 +1,12 @@
import hashlib import hashlib
import json
import logging import logging
import math
import os import os
import subprocess import subprocess
import tempfile import tempfile
from src.Utils import calcDownloadPath from src.Utils import calcDownloadPath
from src.Config import Config from src.Config import Config
log = logging.getLogger('segments')
class Segments: class Segments:
config: Config = None config: Config = None
@ -111,7 +110,7 @@ class Segments:
ffmpegCmd.append('mpegts') ffmpegCmd.append('mpegts')
ffmpegCmd.append('pipe:1') ffmpegCmd.append('pipe:1')
logging.debug( log.debug(
f'Streaming {realFile} segment {self.segment_index}.' + ' '.join(ffmpegCmd)) f'Streaming {realFile} segment {self.segment_index}.' + ' '.join(ffmpegCmd))
proc = subprocess.run(ffmpegCmd, stdout=subprocess.PIPE) proc = subprocess.run(ffmpegCmd, stdout=subprocess.PIPE)