Add logging observability (#1999)

SciPhi-AI · Feb 22, 2025 · 88c3b1a · 88c3b1a
1 parent b0a32df
commit 88c3b1a
Show file tree

Hide file tree

Showing 8 changed files with 196 additions and 82 deletions.
diff --git a/compose.full.swarm.yaml b/compose.full.swarm.yaml
@@ -246,6 +246,7 @@ services:
 
       # R2R
       - R2R_LOG_LEVEL=${R2R_LOG_LEVEL:-INFO}
+      - R2R_LOG_CONSOLE_FORMATTER=${R2R_LOG_CONSOLE_FORMATTER:-json}
       - R2R_CONFIG_NAME=${R2R_CONFIG_NAME:-}
       - R2R_CONFIG_PATH=${R2R_CONFIG_PATH:-}
       - R2R_PROJECT_NAME=${R2R_PROJECT_NAME:-r2r_default}
@@ -376,6 +377,12 @@ services:
       rollback_config:
         parallelism: 1
         delay: 30s
+    logging:
+      driver: fluentd
+      options:
+        fluentd-address: host.docker.internal:24224
+        fluentd-sub-second-precision: "true"
+        tag: backend
 
   r2r-dashboard:
     image: ${R2R_DASHBOARD_IMAGE:-emrgntcmplxty/r2r-dashboard:latest}
@@ -388,3 +395,29 @@ services:
       replicas: 1
       restart_policy:
         condition: on-failure
+
+  fluent-bit:
+    image: fluent/fluent-bit:latest
+    volumes:
+    - ./docker/fluent-bit:/fluent-bit/etc:ro
+    ports:
+    - "24224:24224"
+    depends_on:
+    - victoria-logs
+
+  grafana:
+    image: grafana/grafana:latest
+    ports:
+    - "3001:3000"
+    env_file:
+    - .env
+    volumes:
+    - ./.data/grafana:/var/lib/grafana
+
+  victoria-logs:
+    image: victoriametrics/victoria-logs:v1.10.1-victorialogs
+    ports:
+    - "9428:9428"
+    volumes:
+    - ./.data/victoria-logs:/data
+    command: -storageDataPath=/data -retentionPeriod=60d
diff --git a/compose.full.yaml b/compose.full.yaml
@@ -262,6 +262,7 @@ services:
 
       # R2R
       - R2R_LOG_LEVEL=${R2R_LOG_LEVEL:-INFO}
+      - R2R_LOG_CONSOLE_FORMATTER=${R2R_LOG_CONSOLE_FORMATTER:-json}
       - R2R_CONFIG_NAME=${R2R_CONFIG_NAME:-}
       - R2R_CONFIG_PATH=${R2R_CONFIG_PATH:-}
       - R2R_PROJECT_NAME=${R2R_PROJECT_NAME:-r2r_default}
@@ -384,6 +385,12 @@ services:
         condition: service_healthy
       graph_clustering:
         condition: service_healthy
+    logging:
+      driver: fluentd
+      options:
+        fluentd-address: host.docker.internal:24224
+        fluentd-sub-second-precision: "true"
+        tag: backend
 
   r2r-dashboard:
     image: ${R2R_DASHBOARD_IMAGE:-emrgntcmplxty/r2r-dashboard:latest}
@@ -392,3 +399,29 @@ services:
       - NEXT_PUBLIC_HATCHET_DASHBOARD_URL=${HATCHET_DASHBOARD_URL:-http://localhost:${R2R_HATCHET_DASHBOARD_PORT:-7274}}
     ports:
       - "${R2R_DASHBOARD_PORT:-7273}:3000"
+
+  fluent-bit:
+    image: fluent/fluent-bit:latest
+    volumes:
+    - ./docker/fluent-bit:/fluent-bit/etc:ro
+    ports:
+    - "24224:24224"
+    depends_on:
+    - victoria-logs
+
+  grafana:
+    image: grafana/grafana:latest
+    ports:
+    - "3001:3000"
+    env_file:
+    - .env
+    volumes:
+    - ./.data/grafana:/var/lib/grafana
+
+  victoria-logs:
+    image: victoriametrics/victoria-logs:v1.10.1-victorialogs
+    ports:
+    - "9428:9428"
+    volumes:
+    - ./.data/victoria-logs:/data
+    command: -storageDataPath=/data -retentionPeriod=60d
diff --git a/docker/fluent-bit/fluent-bit.conf b/docker/fluent-bit/fluent-bit.conf
@@ -0,0 +1,26 @@
+[SERVICE]
+    Flush        1
+    Daemon       Off
+    Log_Level    info
+    Parsers_File parsers.conf
+
+[INPUT]
+    Tag    backend
+    Name   forward
+    Listen 0.0.0.0
+    Port   24224
+
+[FILTER]
+    Match    backend
+    Name     parser
+    Key_Name log
+    Parser   json
+
+[OUTPUT]
+    Match            backend
+    Name             http
+    host             host.docker.internal
+    port             9428
+    uri              /insert/jsonline?_stream_fields=log&_msg_field=msg,message&_time_field=date
+    format           json_lines
+    json_date_format iso8601
diff --git a/docker/fluent-bit/parsers.conf b/docker/fluent-bit/parsers.conf
@@ -0,0 +1,3 @@
+[PARSER]
+    Name   json
+    Format json
diff --git a/py/core/main/app_entry.py b/py/core/main/app_entry.py
@@ -1,4 +1,5 @@
 import os
+import logging
 from contextlib import asynccontextmanager
 from typing import Optional
 
@@ -12,7 +13,7 @@
 
 from .assembly import R2RBuilder, R2RConfig
 
-logger, log_file = configure_logging()
+log_file = configure_logging()
 
 # Global scheduler
 scheduler = AsyncIOScheduler()
@@ -72,23 +73,23 @@ async def create_r2r_app(
 host = os.getenv("R2R_HOST", os.getenv("HOST", "0.0.0.0"))
 port = int(os.getenv("R2R_PORT", "7272"))
 
-logger.info(
+logging.info(
     f"Environment R2R_CONFIG_NAME: {'None' if config_name is None else config_name}"
 )
-logger.info(
+logging.info(
     f"Environment R2R_CONFIG_PATH: {'None' if config_path is None else config_path}"
 )
-logger.info(f"Environment R2R_PROJECT_NAME: {os.getenv('R2R_PROJECT_NAME')}")
+logging.info(f"Environment R2R_PROJECT_NAME: {os.getenv('R2R_PROJECT_NAME')}")
 
-logger.info(f"Environment R2R_POSTGRES_HOST: {os.getenv('R2R_POSTGRES_HOST')}")
-logger.info(
+logging.info(f"Environment R2R_POSTGRES_HOST: {os.getenv('R2R_POSTGRES_HOST')}")
+logging.info(
     f"Environment R2R_POSTGRES_DBNAME: {os.getenv('R2R_POSTGRES_DBNAME')}"
 )
-logger.info(f"Environment R2R_POSTGRES_PORT: {os.getenv('R2R_POSTGRES_PORT')}")
-logger.info(
+logging.info(f"Environment R2R_POSTGRES_PORT: {os.getenv('R2R_POSTGRES_PORT')}")
+logging.info(
     f"Environment R2R_POSTGRES_PASSWORD: {os.getenv('R2R_POSTGRES_PASSWORD')}"
 )
-logger.info(
+logging.info(
     f"Environment R2R_PROJECT_NAME: {os.getenv('R2R_PR2R_PROJECT_NAME')}"
 )
 

diff --git a/py/core/utils/logging_config.py b/py/core/utils/logging_config.py
@@ -70,82 +70,88 @@ def filter(self, record: logging.LogRecord) -> bool:
         return True
 
 
-def configure_logging():
-    # Read the desired log level from the environment (default to DEBUG)
-    log_level = os.environ.get("R2R_LOG_LEVEL", "INFO").upper()
-
-    # Create a logs directory if it does not already exist
-    log_dir = Path.cwd() / "logs"
-    log_dir.mkdir(exist_ok=True)
-
-    log_config = {
-        "version": 1,
-        "disable_existing_loggers": False,
-        "filters": {
-            "http_status_filter": {
-                "()": HTTPStatusFilter,
-            }
+log_level = os.environ.get("R2R_LOG_LEVEL", "INFO").upper()
+log_console_formatter = os.environ.get("R2R_LOG_CONSOLE_FORMATTER", "colored").lower() # colored or json
+
+log_dir = Path.cwd() / "logs"
+log_dir.mkdir(exist_ok=True)
+log_file = log_dir / "app.log"
+
+log_config = {
+    "version": 1,
+    "disable_existing_loggers": False,
+    "filters": {
+        "http_status_filter": {
+            "()": HTTPStatusFilter,
+        }
+    },
+    "formatters": {
+        "default": {
+            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+            "datefmt": "%Y-%m-%d %H:%M:%S",
         },
-        "formatters": {
-            "default": {
-                "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
-                "datefmt": "%Y-%m-%d %H:%M:%S",
-            },
-            "colored": {
-                "()": "colorlog.ColoredFormatter",
-                "format": "%(asctime)s - %(log_color)s%(levelname)s%(reset)s - %(message)s",
-                "datefmt": "%Y-%m-%d %H:%M:%S",
-                "log_colors": {
-                    "DEBUG": "white",
-                    "INFO": "green",
-                    "WARNING": "yellow",
-                    "ERROR": "red",
-                    "CRITICAL": "bold_red",
-                },
+        "colored": {
+            "()": "colorlog.ColoredFormatter",
+            "format": "%(asctime)s - %(log_color)s%(levelname)s%(reset)s - %(message)s",
+            "datefmt": "%Y-%m-%d %H:%M:%S",
+            "log_colors": {
+                "DEBUG": "white",
+                "INFO": "green",
+                "WARNING": "yellow",
+                "ERROR": "red",
+                "CRITICAL": "bold_red",
             },
         },
-        "handlers": {
-            "file": {
-                "class": "logging.handlers.RotatingFileHandler",
-                "formatter": "colored",
-                "filename": str(log_dir / "app.log"),
-                "maxBytes": 10485760,  # 10MB
-                "backupCount": 5,
-                "filters": ["http_status_filter"],
-                "level": log_level,  # Set handler level based on the environment variable
-            },
-            "console": {
-                "class": "logging.StreamHandler",
-                "formatter": "colored",
-                "stream": sys.stdout,
-                "filters": ["http_status_filter"],
-                "level": log_level,  # Set handler level based on the environment variable
-            },
+        "json": {
+            "()": "pythonjsonlogger.json.JsonFormatter",
+            "format": "%(name)s %(levelname)s %(message)s", # these become keys in the JSON log
+            "rename_fields": {"asctime": "time", "levelname": "level", "name": "logger"},
         },
-        "loggers": {
-            "": {  # Root logger
-                "handlers": ["console", "file"],
-                "level": log_level,  # Set logger level based on the environment variable
-            },
-            "uvicorn": {
-                "handlers": ["console", "file"],
-                "level": log_level,
-                "propagate": False,
-            },
-            "uvicorn.error": {
-                "handlers": ["console", "file"],
-                "level": log_level,
-                "propagate": False,
-            },
-            "uvicorn.access": {
-                "handlers": ["console", "file"],
-                "level": log_level,
-                "propagate": False,
-            },
+    },
+    "handlers": {
+        "file": {
+            "class": "logging.handlers.RotatingFileHandler",
+            "formatter": "colored",
+            "filename": log_file,
+            "maxBytes": 10485760,  # 10MB
+            "backupCount": 5,
+            "filters": ["http_status_filter"],
+            "level": log_level,  # Set handler level based on the environment variable
         },
-    }
+        "console": {
+            "class": "logging.StreamHandler",
+            "formatter": log_console_formatter,
+            "stream": sys.stdout,
+            "filters": ["http_status_filter"],
+            "level": log_level,  # Set handler level based on the environment variable
+        },
+    },
+    "loggers": {
+        "": {  # Root logger
+            "handlers": ["console", "file"],
+            "level": log_level,  # Set logger level based on the environment variable
+        },
+        "uvicorn": {
+            "handlers": ["console", "file"],
+            "level": log_level,
+            "propagate": False,
+        },
+        "uvicorn.error": {
+            "handlers": ["console", "file"],
+            "level": log_level,
+            "propagate": False,
+        },
+        "uvicorn.access": {
+            "handlers": ["console", "file"],
+            "level": log_level,
+            "propagate": False,
+        },
+    },
+}
 
+def configure_logging() -> Path:
     logging.config.dictConfig(log_config)
-    logger = logging.getLogger()
-    logger.info(f"Logging is configured at {log_level} level.")
-    return logger, Path(log_config["handlers"]["file"]["filename"])
+
+    logging.info(f"Logging is configured at {log_level} level.")
+
+    return log_file
diff --git a/py/pyproject.toml b/py/pyproject.toml
@@ -27,6 +27,7 @@ dependencies = [
     "types-aiofiles >=24.1.0.20240626,<25.0.0",
     "typing-extensions >=4.12.2,<5.0.0",
     "pydantic>=2.10.6",
+    "python-json-logger>=3.2.1",
 ]
 
 [project.optional-dependencies]

diff --git a/py/uv.lock b/py/uv.lock