From edf06944e05141a125f76e7971dd88a5533c7825 Mon Sep 17 00:00:00 2001 From: Mikhail Epifanov Date: Wed, 10 Jul 2024 10:29:11 +0200 Subject: [PATCH] enable logging for whole project and add more logging to connectors --- cookbook/connectors/connector_manager.py | 17 ++++++--- cookbook/connectors/homeassistant.py | 2 +- recipes/settings.py | 45 ++++++++++++++++-------- 3 files changed, 45 insertions(+), 19 deletions(-) diff --git a/cookbook/connectors/connector_manager.py b/cookbook/connectors/connector_manager.py index e247db305..487aeca0d 100644 --- a/cookbook/connectors/connector_manager.py +++ b/cookbook/connectors/connector_manager.py @@ -5,6 +5,7 @@ import threading from asyncio import Task from dataclasses import dataclass from enum import Enum +from logging import Logger from types import UnionType from typing import List, Any, Dict, Optional, Type @@ -39,10 +40,12 @@ class Work: # 4. Work is marked as consumed, and next entry of the queue is consumed. # Each 'Work' is processed in sequential by the worker, so the throughput is about [workers * the slowest connector] class ConnectorManager: + _logger: Logger _queue: queue.Queue _listening_to_classes = REGISTERED_CLASSES | ConnectorConfig def __init__(self): + self._logger = logging.getLogger("recipes.connector") self._queue = queue.Queue(maxsize=settings.EXTERNAL_CONNECTORS_QUEUE_SIZE) self._worker = threading.Thread(target=self.worker, args=(0, self._queue,), daemon=True) self._worker.start() @@ -65,7 +68,7 @@ class ConnectorManager: try: self._queue.put_nowait(Work(instance, action_type)) except queue.Full: - logging.info(f"queue was full, so skipping {action_type} of type {type(instance)}") + self._logger.info(f"queue was full, so skipping {action_type} of type {type(instance)}") return def stop(self): @@ -74,10 +77,12 @@ class ConnectorManager: @staticmethod def worker(worker_id: int, worker_queue: queue.Queue): + logger = logging.getLogger("recipes.connector.worker") + loop = asyncio.new_event_loop() asyncio.set_event_loop(loop) - logging.info(f"started ConnectionManager worker {worker_id}") + logger.info(f"started ConnectionManager worker {worker_id}") # When multiple workers are used, please make sure the cache is shared across all threads, otherwise it might lead to un-expected behavior. _connectors_cache: Dict[int, List[Connector]] = dict() @@ -91,6 +96,8 @@ class ConnectorManager: if item is None: break + logger.debug(f"received {item.instance=} with {item.actionType=}") + # If a Connector was changed/updated, refresh connector from the database for said space refresh_connector_cache = isinstance(item.instance, ConnectorConfig) @@ -111,7 +118,7 @@ class ConnectorManager: try: connector: Optional[Connector] = ConnectorManager.get_connected_for_config(config) except BaseException: - logging.exception(f"failed to initialize {config.name}") + logger.exception(f"failed to initialize {config.name}") continue if connector is not None: @@ -123,10 +130,12 @@ class ConnectorManager: worker_queue.task_done() continue + logger.debug(f"running {len(connectors)} connectors for {item.instance=} with {item.actionType=}") + loop.run_until_complete(run_connectors(connectors, space, item.instance, item.actionType)) worker_queue.task_done() - logging.info(f"terminating ConnectionManager worker {worker_id}") + logger.info(f"terminating ConnectionManager worker {worker_id}") asyncio.set_event_loop(None) loop.close() diff --git a/cookbook/connectors/homeassistant.py b/cookbook/connectors/homeassistant.py index f824a4262..e821e2076 100644 --- a/cookbook/connectors/homeassistant.py +++ b/cookbook/connectors/homeassistant.py @@ -20,7 +20,7 @@ class HomeAssistant(Connector): if config.url[-1] != "/": config.url += "/" self._config = config - self._logger = logging.getLogger("connector.HomeAssistant") + self._logger = logging.getLogger("recipes.connector.HomeAssistant") async def homeassistant_api_call(self, method: str, path: str, data: Dict) -> str: headers = { diff --git a/recipes/settings.py b/recipes/settings.py index d9b2b6b24..5454edc95 100644 --- a/recipes/settings.py +++ b/recipes/settings.py @@ -30,6 +30,8 @@ SECRET_KEY = os.getenv('SECRET_KEY') if os.getenv('SECRET_KEY') else 'INSECURE_S DEBUG = bool(int(os.getenv('DEBUG', True))) DEBUG_TOOLBAR = bool(int(os.getenv('DEBUG_TOOLBAR', True))) +LOG_LEVEL = os.getenv("DJANGO_LOG_LEVEL", "INFO") + SOCIAL_DEFAULT_ACCESS = bool(int(os.getenv('SOCIAL_DEFAULT_ACCESS', False))) SOCIAL_DEFAULT_GROUP = os.getenv('SOCIAL_DEFAULT_GROUP', 'guest') @@ -40,6 +42,31 @@ SPACE_DEFAULT_ALLOW_SHARING = bool(int(os.getenv('SPACE_DEFAULT_ALLOW_SHARING', INTERNAL_IPS = os.getenv('INTERNAL_IPS').split(',') if os.getenv('INTERNAL_IPS') else ['127.0.0.1'] +# Django Logging +LOGGING = { + "version": 1, + "disable_existing_loggers": False, + 'formatters': { + 'verbose': { + 'format': '{levelname} {asctime} {module} {message}', + 'style': '{', + }, + }, + "handlers": { + "console": { + "class": "logging.StreamHandler", + 'formatter': 'verbose', + }, + }, + "loggers": { + 'recipes': { + 'handlers': ['console'], + 'level': LOG_LEVEL, + }, + }, +} + + # allow djangos wsgi server to server mediafiles GUNICORN_MEDIA = bool(int(os.getenv('GUNICORN_MEDIA', False))) @@ -254,22 +281,12 @@ if LDAP_AUTH: if 'AUTH_LDAP_TLS_CACERTFILE' in os.environ: AUTH_LDAP_GLOBAL_OPTIONS = {ldap.OPT_X_TLS_CACERTFILE: os.getenv('AUTH_LDAP_TLS_CACERTFILE')} if DEBUG: - LOGGING = { - "version": 1, - "disable_existing_loggers": False, - "handlers": { - "console": { - "class": "logging.StreamHandler" - } - }, - "loggers": { - "django_auth_ldap": { - "level": "DEBUG", - "handlers": ["console"] - } - }, + LOGGING["loggers"]["django_auth_ldap"] = { + "level": "DEBUG", + "handlers": ["console"] } + AUTHENTICATION_BACKENDS += [ 'django.contrib.auth.backends.ModelBackend', 'allauth.account.auth_backends.AuthenticationBackend',