Merge pull request #4961 from FinnStutzenstein/loggingRedis

Logging prefix and handling redis connection errors

openslides/core/apps.py

@@ -1,4 +1,3 @@
-import logging
 import os
 import sys
 from collections import OrderedDict
@@ -9,6 +8,7 @@ from django.apps import AppConfig
 from django.conf import settings
 from django.db.models.signals import post_migrate, pre_delete
 
+from openslides.utils import logging
 from openslides.utils.schema_version import schema_version_handler
 
 

openslides/core/signals.py

@@ -1,4 +1,3 @@
-import logging
 import sys
 from collections import defaultdict
 from typing import Dict, List
@@ -9,6 +8,7 @@ from django.contrib.contenttypes.models import ContentType
 from django.db.models import Q
 from django.dispatch import Signal
 
+from ..utils import logging
 from ..utils.autoupdate import Element, inform_changed_elements
 
 

openslides/utils/cache.py

@@ -1,5 +1,4 @@
 import json
-import logging
 from collections import defaultdict
 from datetime import datetime
 from time import sleep
@@ -8,6 +7,7 @@ from typing import Any, Callable, Dict, List, Optional, Tuple, Type
 from asgiref.sync import async_to_sync
 from django.apps import apps
 
+from . import logging
 from .cache_providers import (
     Cachable,
     ElementCacheProvider,

openslides/utils/cache_providers.py

@@ -1,6 +1,5 @@
 import functools
 import hashlib
-import logging
 from collections import defaultdict
 from textwrap import dedent
 from typing import Any, Callable, Coroutine, Dict, List, Optional, Set, Tuple
@@ -8,6 +7,7 @@ from typing import Any, Callable, Coroutine, Dict, List, Optional, Set, Tuple
 from django.core.exceptions import ImproperlyConfigured
 from typing_extensions import Protocol
 
+from . import logging
 from .redis import use_redis
 from .schema_version import SchemaVersion
 from .utils import split_element_id, str_dict_to_bytes

openslides/utils/consumers.py

@@ -1,10 +1,10 @@
-import logging
 import time
 from collections import defaultdict
 from typing import Any, Dict, List, Optional
 from urllib.parse import parse_qs
 
 from ..utils.websocket import WEBSOCKET_CHANGE_ID_TOO_HIGH
+from . import logging
 from .auth import async_anonymous_is_enabled
 from .autoupdate import AutoupdateFormat
 from .cache import element_cache, split_element_id

openslides/utils/logging.py

@@ -0,0 +1,29 @@
+import logging as python_logging
+from typing import Any, MutableMapping, Tuple
+
+from .utils import get_worker_id
+
+
+class LoggerAdapter(python_logging.LoggerAdapter):
+    """
+    Custom adapter for adding a prefix given in the constructor to every log
+    statement.
+    """
+
+    def __init__(self, prefix: str, logger: python_logging.Logger) -> None:
+        super().__init__(logger, {})
+        self.prefix = prefix
+
+    def process(
+        self, msg: str, kwargs: MutableMapping[str, Any]
+    ) -> Tuple[str, MutableMapping[str, Any]]:
+        return f"[{self.prefix}] {msg}", kwargs
+
+
+def getLogger(name: str) -> LoggerAdapter:
+    """
+    This method is for a drop-in replacement for the loggging module:
+    Use `from openslides.utils import logging` instead of `import logging`
+    """
+    logger = python_logging.getLogger(name)
+    return LoggerAdapter(get_worker_id(), logger)

openslides/utils/models.py

@@ -1,10 +1,10 @@
-import logging
 import time
 from typing import Any, Dict, List, Optional
 
 from django.core.exceptions import ImproperlyConfigured
 from django.db import models
 
+from . import logging
 from .access_permissions import BaseAccessPermissions
 from .autoupdate import Element, inform_changed_data, inform_changed_elements
 from .rest_api import model_serializer_classes

openslides/utils/redis.py

@@ -4,6 +4,10 @@ from typing import Any
 from channels_redis.core import ConnectionPool
 from django.conf import settings
 
+from . import logging
+
+
+logger = logging.getLogger(__name__)
 
 try:
     import aioredis
@@ -13,7 +17,8 @@ else:
     # set use_redis to true, if there is a value for REDIS_ADDRESS in the settings
     redis_address = getattr(settings, "REDIS_ADDRESS", "")
     use_redis = bool(redis_address)
-
+    if use_redis:
+        logger.info(f"Redis address {redis_address}")
 
 pool = ConnectionPool({"address": redis_address})
 semaphore = asyncio.Semaphore(100)
@@ -32,7 +37,13 @@ class RedisConnectionContextManager:
         return self.conn
 
     async def __aexit__(self, exc_type: Any, exc: Any, tb: Any) -> None:
+        if exc:
+            logger.warn(f"Redis Exception: {exc}. Do not reuse connection...")
+            pool.conn_error(self.conn)
+        else:
             pool.push(self.conn)
+        self.conn = None
+
         semaphore.release()
 
 

openslides/utils/schema_version.py

@@ -1,9 +1,10 @@
-import logging
 from typing import Optional
 
 from django.db.models import Max
 from mypy_extensions import TypedDict
 
+from . import logging
+
 
 logger = logging.getLogger(__name__)
 SchemaVersion = TypedDict("SchemaVersion", {"migration": int, "config": int, "db": str})

openslides/utils/stats.py

@@ -1,8 +1,9 @@
 import asyncio
-import logging
 import time
 from typing import List, Optional
 
+from . import logging
+
 
 class WebsocketLatencyLogger:
     """