Added telementry and loguru

backend/requirements/base.txt

@@ -27,4 +27,34 @@ XlsxWriter==3.1.9
 pydub==0.25.1
 django-celery-results==2.5.1
 django-environ==0.11.2
-pytz==2024.1
+pytz==2024.1
+opentelemetry-api==1.22.0
+opentelemetry-distro==0.43b0
+opentelemetry-exporter-otlp==1.22.0
+opentelemetry-exporter-otlp-proto-common==1.22.0
+opentelemetry-exporter-otlp-proto-grpc==1.22.0
+opentelemetry-exporter-otlp-proto-http==1.22.0
+opentelemetry-instrumentation==0.43b0
+opentelemetry-instrumentation-asgi==0.43b0
+opentelemetry-instrumentation-aws-lambda==0.43b0
+opentelemetry-instrumentation-boto3sqs==0.43b0
+opentelemetry-instrumentation-botocore==0.43b0
+opentelemetry-instrumentation-celery==0.43b0
+opentelemetry-instrumentation-dbapi==0.43b0
+opentelemetry-instrumentation-django==0.43b0
+opentelemetry-instrumentation-grpc==0.43b0
+opentelemetry-instrumentation-jinja2==0.43b0
+opentelemetry-instrumentation-logging==0.43b0
+opentelemetry-instrumentation-psycopg2==0.43b0
+opentelemetry-instrumentation-redis==0.43b0
+opentelemetry-instrumentation-requests==0.43b0
+opentelemetry-instrumentation-sqlite3==0.43b0
+opentelemetry-instrumentation-urllib==0.43b0
+opentelemetry-instrumentation-urllib3==0.43b0
+opentelemetry-instrumentation-wsgi==0.43b0
+opentelemetry-propagator-aws-xray==1.0.1
+opentelemetry-proto==1.22.0
+opentelemetry-sdk==1.22.0
+opentelemetry-semantic-conventions==0.43b0
+opentelemetry-util-http==0.43b0
+loguru==0.7.2

backend/src/zelthy/cli/project_template/project_name/settings.py

@@ -13,6 +13,8 @@
 
 SECRET_KEY = "{{secret_key}}"
 
+OTEL_IS_ENABLED = True
+
 # SECURITY WARNING: don't run with debug turned on in production!
 DEBUG = True
 
@@ -116,3 +118,19 @@
 STATIC_ROOT = os.path.join(BASE_DIR, "static")
 STATIC_URL = "static/"
 STATICFILES_DIRS += [os.path.join(BASE_DIR, "assets")]
+
+
+log_folder = os.path.join(BASE_DIR, 'log')
+log_file = os.path.join(log_folder, 'server.log')
+
+# Check if the log folder exists, if not, create it
+if not os.path.exists(log_folder):
+    os.makedirs(log_folder)
+
+# Check if the log file exists, if not, create it
+if not os.path.exists(log_file):
+    with open(log_file, 'a'):
+        pass  # Create an empty file
+
+
+LOGGING['handlers']['file']['filename'] =  log_file

backend/src/zelthy/cli/project_template/project_name/telementry_utlis.py

@@ -0,0 +1,92 @@
+import os
+import uuid
+import logging
+import traceback
+import inspect
+import functools
+from pathlib import Path
+from opentelemetry import trace
+from opentelemetry.sdk.trace import TracerProvider
+from opentelemetry.sdk.trace.export import ConsoleSpanExporter
+from opentelemetry.sdk.trace.export import BatchSpanProcessor
+from opentelemetry.propagate import extract
+from loguru import logger
+
+from typing import List, Optional, Union
+from opentelemetry.trace import Status, StatusCode, Tracer, get_current_span
+
+
+tracer = trace.get_tracer(__name__)
+
+
+def _zelthy_trace_func(wrapped_func, tracer: Tracer):
+    @functools.wraps(wrapped_func)
+    def _wrapper(*args, **kwargs):
+        with tracer.start_as_current_span(
+            wrapped_func.__module__ + "." + wrapped_func.__qualname__
+        ) as span:
+            try:
+                result = wrapped_func(*args, **kwargs)
+            except Exception as ex:
+                span.set_status(Status(StatusCode.ERROR))
+                span.record_exception(ex)
+                raise ex
+
+        return result
+
+    return _wrapper
+
+def zelthy_trace_methods(
+    tracer: Tracer,
+    only: Optional[Union[str, List[str]]] = None,
+    exclude: Optional[Union[str, List[str]]] = None,
+    abc: bool = False,
+):
+    """
+    Automatically traces all public methods, or specific methods of a class depending
+    on the arguments.
+
+    You need to use this if you want to say, trace every implementation of an abstract
+    method as decorating the method itself will get overriden by the subclasses where-as
+    this metaclass will wrap the method when the subclass itself is created (the class
+    not the instances!)
+
+    If you want to use this metaclass and abc.ABC, use this and set abc=True.
+
+    Using a metaclass is the python recommended way of automatically decorating
+    all/some functions in a class.
+
+    :param tracer: An otel Tracer, add `tracer = trace.get_tracer(__name__)` to the top
+        of your file to get one.
+    :param only: The name of the only function you want to trace or a list of names.
+    :param exclude: The name of the function you do not want to trace or a list of
+    names.
+    :param abc: Whether this class should also be an abstract base class.
+    """
+
+    if only and not isinstance(only, list):
+        only = [only]
+    if exclude and not isinstance(exclude, list):
+        exclude = [exclude]
+
+    super_class = ABCMeta if abc else type
+
+    class TraceMethodsMetaClass(super_class):
+        def __new__(cls, name, bases, local):
+            for attr in local:
+                if cls._should_trace_attr(attr):
+                    continue
+                value = local[attr]
+                if inspect.isfunction(value):
+                    local[attr] = _zelthy_trace_func(value, tracer)
+            return super().__new__(cls, name, bases, local)
+
+        @staticmethod
+        def _should_trace_attr(attr):
+            return (
+                attr.startswith("_")
+                or (only and attr not in only)
+                or (exclude and attr in exclude)
+            )
+
+    return TraceMethodsMetaClass

backend/src/zelthy/cli/project_template/project_name/telemetry.py

@@ -0,0 +1,142 @@
+import os
+import sys
+import uuid
+import logging
+from pathlib import Path
+from loguru import logger
+from .settings import OTEL_IS_ENABLED
+from opentelemetry import metrics, trace
+from opentelemetry._logs import set_logger_provider
+from opentelemetry.exporter.otlp.proto.http._log_exporter import OTLPLogExporter
+from opentelemetry.exporter.otlp.proto.http.metric_exporter import OTLPMetricExporter
+from opentelemetry.exporter.otlp.proto.http.trace_exporter import OTLPSpanExporter
+from opentelemetry.instrumentation.botocore import BotocoreInstrumentor
+from opentelemetry.instrumentation.celery import CeleryInstrumentor
+from opentelemetry.instrumentation.django import DjangoInstrumentor
+from opentelemetry.instrumentation.psycopg2 import Psycopg2Instrumentor
+from opentelemetry.instrumentation.redis import RedisInstrumentor
+from opentelemetry.instrumentation.requests import RequestsInstrumentor
+from opentelemetry.sdk._logs import LoggerProvider, LoggingHandler
+from opentelemetry.sdk._logs._internal.export import BatchLogRecordProcessor
+from opentelemetry.sdk.metrics import MeterProvider
+from opentelemetry.sdk.metrics._internal.export import PeriodicExportingMetricReader
+from opentelemetry.trace import ProxyTracerProvider
+
+
+from opentelemetry.sdk.trace.export import BatchSpanProcessor
+from opentelemetry.sdk.trace.export import ConsoleSpanExporter
+from opentelemetry.sdk.trace import TracerProvider
+from opentelemetry import trace
+
+BASE_DIR = Path(__file__).resolve().parent.parent
+
+
+class LogGuruCompatibleLoggerHandler(LoggingHandler):
+    def emit(self, record: logging.LogRecord) -> None:
+        # The Otel exporter does not handle nested dictionaries. Loguru stores all of
+        # the extra log context developers can add on the extra dict. Here unnest
+        # them as attributes on the record itself so otel can export them properly.
+        for k, v in record.extra.items():
+            setattr(record, f"zelthy.{k}", v)
+        del record.extra
+
+        # by default otel doesn't send funcName, rename it so it does.
+        setattr(record, "python_function", record.funcName)
+        super().emit(record)
+
+
+def uuid_sink(record):
+    """
+    Custom sink function that adds a UUID to each log record.
+    """
+    # Generate a UUID for the log record
+    record["extra"]["uuid"] = str(uuid.uuid4())
+    return record
+
+
+def setup_logging():
+    """
+    This function configures loguru and optionally sets up open telemetry log exporting
+    using a loguru sink.
+    """
+
+    # A slightly customized default loguru format which includes the process id.
+    loguru_format = (
+        "<magenta>{extra[uuid]}|</magenta>"
+        "<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</green>|"
+        "[{extra[schema_name]}:testlogapp.zelthy.com][{extra[ip_address]}]|"
+        "<level>{level}</level>|"
+        "<cyan>{name}</cyan>:"
+        "<cyan>{function}</cyan>:"
+        "<cyan>{line}</cyan> - "
+        "<level>{message}</level>"
+    )
+
+    # Remove the default loguru stderr sink
+    logger.remove()
+
+    log_folder = os.path.join(BASE_DIR, 'log')
+    log_file = os.path.join(log_folder, 'server.log')
+
+    # Check if the log folder exists, if not, create it
+    if not os.path.exists(log_folder):
+        os.makedirs(log_folder)
+
+    # Check if the log file exists, if not, create it
+    if not os.path.exists(log_file):
+        with open(log_file, 'a'):
+            pass  # Create an empty file
+
+    logger.add(
+        log_file, format=loguru_format, level="INFO", filter=uuid_sink
+    )
+
+    logger.info("Logger setup.")
+
+
+def setup_telemetry(add_django_instrumentation: bool):
+    """
+    Sets up logging and when the env var ZELTHY_ENABLE_OTEL is set to any non-blank
+    string and this function is called metrics will be setup and sent according to
+    the OTEL env vars you can find described at:
+    - https://opentelemetry.io/docs/reference/specification/protocol/exporter/
+    - https://opentelemetry.io/docs/reference/specification/sdk-environment-variables/
+
+    :param add_django_instrumentation: Enables specific instrumentation for a django
+        process that is processing requests. Don't enable this for a celery process etc.
+    """
+
+    if OTEL_IS_ENABLED:
+        _setup_standard_backend_instrumentation()
+
+        # # Add console exporter
+        # console_exporter = ConsoleSpanExporter()
+        # span_processor = BatchSpanProcessor(console_exporter)
+        # # Initialize the TracerProvider
+        # tracer_provider = TracerProvider()
+
+        # # Add the BatchSpanProcessor to the TracerProvider
+        # tracer_provider.add_span_processor(span_processor)
+
+        # # Configure the tracer provider
+        # trace.set_tracer_provider(tracer_provider)
+
+        print("Configured default backend instrumentation")
+        if add_django_instrumentation:
+            print("Adding Django request instrumentation also.")
+            _setup_django_process_instrumentation()
+
+        print("Telemetry enabled!")
+
+
+
+def _setup_standard_backend_instrumentation():
+    BotocoreInstrumentor().instrument()
+    Psycopg2Instrumentor().instrument()
+    RedisInstrumentor().instrument()
+    RequestsInstrumentor().instrument()
+    CeleryInstrumentor().instrument()
+
+
+def _setup_django_process_instrumentation():
+    DjangoInstrumentor().instrument()

backend/src/zelthy/cli/project_template/project_name/wsgi.py

@@ -1,16 +1,21 @@
 """
 WSGI config for testproject project.
-
 It exposes the WSGI callable as a module-level variable named ``application``.
-
 For more information on this file, see
 https://docs.djangoproject.com/en/4.2/howto/deployment/wsgi/
 """
-
 import os
-
 from django.core.wsgi import get_wsgi_application
+from .telemetry import setup_logging, setup_telemetry
+from django.db import connection
+
+# The telemetry instrumentation library setup needs to run prior to django's setup.
+setup_telemetry(add_django_instrumentation=True)
 
 os.environ.setdefault("DJANGO_SETTINGS_MODULE", "{{project_name}}.settings")
 
 application = get_wsgi_application()
+
+# It is critical to setup our own logging after django has been setup and done its own
+# logging setup. Otherwise Django will try to destroy and log handlers we added prior.
+setup_logging()

backend/src/zelthy/config/settings/base.py

@@ -83,6 +83,7 @@
     "corsheaders.middleware.CorsMiddleware",
     "debug_toolbar.middleware.DebugToolbarMiddleware",
     "zelthy.middleware.tenant.TimezoneMiddleware",
+    "zelthy.middleware.logging_middleware.LoggingMiddleware"
 ]
 
 
@@ -163,3 +164,48 @@
 
 PACKAGE_BUCKET_NAME = "zelthy3-packages"
 CODEASSIST_ENABLED = True
+
+LOGGING = {
+    'version': 1,
+    'disable_existing_loggers': False,
+    'handlers': {
+        'loguru': {
+            'level': 'INFO',
+            'class': 'zelthy.core.loguru_handler.LoguruHandler',
+        },
+        'file': {
+            'level': 'INFO', 
+            'class': 'logging.handlers.RotatingFileHandler',
+            'maxBytes': 1024*1024*5, # 5 MB
+            'formatter': 'verbose', # Use the custom formatter
+            'filters': ['custom_filter'],
+        },
+    },
+    'root': {
+        'handlers': ['loguru', 'file'], # Add 'file' handler here if you want to use it
+        'level': 'INFO',
+    },
+    'formatters': {
+        'verbose': {
+            'format': "%(uuid)s [%(schema_name)s:%(domain_url)s][%(remote_addr)s][%(asctime)s] %(levelname)s [%(pathname)s:%(funcName)s:%(lineno)s] %(message)s %(exc_traceback_content)s",
+            'datefmt': "%d/%b/%Y %H:%M:%S"
+        }            
+    },
+    'filters': {
+        'custom_filter': {
+            '()': 'zelthy.core.log_file.CustomFilter',
+        },
+    },
+    'loggers': {
+        'django.request': {
+            'handlers': ['file'],
+            'level': 'INFO',
+            'propagate': True,
+        },
+        'zelthy': {
+            'handlers': ['file'],
+            'level': 'INFO',
+            'propagate': True,
+        }
+    },
+}