feat: Drop loguru and use builtin `logging` (#1133)

* Configure simple builtin logging

Changed the 2 existing `print` in the `private_gpt` code base into actual python logging, stop using loguru (dependency will be dropped in a later commit).
Try to use the `key=value` logging convention in logs (to indicate what dynamic values represents, and what is dynamic vs not).
Using `%s` log style, so that the string formatting is pushed inside the logger, giving the ability to the logger to determine if the string need to be formatted or not (i.e. strings from debug logs might not be formatted if the log level is not debug)
The (basic) builtin log configuration have been placed in `private_gpt/__init__.py` in order to initialize the logging system even before we start to launch any python code in `private_gpt` package (ensuring we get any initialization log formatted as we want to)
Disabled `uvicorn` custom logging format, resulting in having uvicorn logs being outputted in our formatted.

Some more concise format could be used if we want to, especially:
```
COMPACT_LOG_FORMAT = '%(asctime)s.%(msecs)03d [%(levelname)s] %(name)s - %(message)s'
```

Python documentation and cookbook on logging for reference:
* https://docs.python.org/3/library/logging.html
* https://docs.python.org/3/howto/logging.html

* Removing loguru from the dependencies

Result of `poetry remove loguru`

* PR feedback: using `logger` variable name instead of `log`

---------

Co-authored-by: Louis Melchior <louis@jaris.io>

poetry.lock

@@ -1916,24 +1916,6 @@ typing-extensions = ">=4.5.0"
 typing-inspect = ">=0.8.0"
 urllib3 = "<2"
 
-[[package]]
-name = "loguru"
-version = "0.7.2"
-description = "Python logging made (stupidly) simple"
-optional = false
-python-versions = ">=3.5"
-files = [
-    {file = "loguru-0.7.2-py3-none-any.whl", hash = "sha256:003d71e3d3ed35f0f8984898359d65b79e5b21943f78af86aa5491210429b8eb"},
-    {file = "loguru-0.7.2.tar.gz", hash = "sha256:e671a53522515f34fd406340ee968cb9ecafbc4b36c679da03c18fd8d0bd51ac"},
-]
-
-[package.dependencies]
-colorama = {version = ">=0.3.4", markers = "sys_platform == \"win32\""}
-win32-setctime = {version = ">=1.0.0", markers = "sys_platform == \"win32\""}
-
-[package.extras]
-dev = ["Sphinx (==7.2.5)", "colorama (==0.4.5)", "colorama (==0.4.6)", "exceptiongroup (==1.1.3)", "freezegun (==1.1.0)", "freezegun (==1.2.2)", "mypy (==v0.910)", "mypy (==v0.971)", "mypy (==v1.4.1)", "mypy (==v1.5.1)", "pre-commit (==3.4.0)", "pytest (==6.1.2)", "pytest (==7.4.0)", "pytest-cov (==2.12.1)", "pytest-cov (==4.1.0)", "pytest-mypy-plugins (==1.9.3)", "pytest-mypy-plugins (==3.0.0)", "sphinx-autobuild (==2021.3.14)", "sphinx-rtd-theme (==1.3.0)", "tox (==3.27.1)", "tox (==4.11.0)"]
-
 [[package]]
 name = "markupsafe"
 version = "2.1.3"
@@ -5154,20 +5136,6 @@ files = [
 [package.extras]
 test = ["pytest (>=6.0.0)", "setuptools (>=65)"]
 
-[[package]]
-name = "win32-setctime"
-version = "1.1.0"
-description = "A small Python utility to set file creation time on Windows"
-optional = false
-python-versions = ">=3.5"
-files = [
-    {file = "win32_setctime-1.1.0-py3-none-any.whl", hash = "sha256:231db239e959c2fe7eb1d7dc129f11172354f98361c4fa2d6d2d7e278baa8aad"},
-    {file = "win32_setctime-1.1.0.tar.gz", hash = "sha256:15cf5750465118d6929ae4de4eb46e8edae9a5634350c01ba582df868e932cb2"},
-]
-
-[package.extras]
-dev = ["black (>=19.3b0)", "pytest (>=4.6.2)"]
-
 [[package]]
 name = "wrapt"
 version = "1.15.0"
@@ -5357,4 +5325,4 @@ testing = ["big-O", "jaraco.functools", "jaraco.itertools", "more-itertools", "p
 [metadata]
 lock-version = "2.0"
 python-versions = ">=3.11,<3.12"
-content-hash = "02ab2873e2074cbed0b415f5fa8addce0fd945487d12944f4c8043d4fc617de9"
+content-hash = "28fe3510739b539671c6cf447706c17934c31094f1a860e9e95452d9e63f5a46"

private_gpt/__init__.py

@@ -1 +1,11 @@
 """private-gpt."""
+import logging
+
+# Set to 'DEBUG' to have extensive logging turned on, even for libraries
+ROOT_LOG_LEVEL = "INFO"
+
+PRETTY_LOG_FORMAT = (
+    "%(asctime)s.%(msecs)03d [%(levelname)-8s] %(name)+25s - %(message)s"
+)
+logging.basicConfig(level=ROOT_LOG_LEVEL, format=PRETTY_LOG_FORMAT, datefmt="%H:%M:%S")
+logging.captureWarnings(True)

private_gpt/__main__.py

@@ -5,4 +5,7 @@ import uvicorn
 from private_gpt.main import app
 from private_gpt.settings.settings import settings
 
-uvicorn.run(app, host="0.0.0.0", port=settings.server.port)
+# Set log_config=None to do not use the uvicorn logging configuration, and
+# use ours instead. For reference, see below:
+# https://github.com/tiangolo/fastapi/discussions/7457#discussioncomment-5141108
+uvicorn.run(app, host="0.0.0.0", port=settings.server.port, log_config=None)

private_gpt/components/llm/custom/sagemaker.py

@@ -3,6 +3,7 @@ from __future__ import annotations
 
 import io
 import json
+import logging
 from typing import TYPE_CHECKING, Any
 
 import boto3  # type: ignore
@@ -26,6 +27,8 @@ if TYPE_CHECKING:
         CompletionResponseGen,
     )
 
+logger = logging.getLogger(__name__)
+
 
 class LineIterator:
     r"""A helper class for parsing the byte stream input from TGI container.
@@ -81,7 +84,7 @@ class LineIterator:
                     continue
                 raise
             if "PayloadPart" not in chunk:
-                print("Unknown event type:" + chunk)
+                logger.warning("Unknown event type=%s", chunk)
                 continue
             self.buffer.seek(0, io.SEEK_END)
             self.buffer.write(chunk["PayloadPart"]["Bytes"])

private_gpt/main.py

@@ -1,11 +1,9 @@
 """FastAPI app creation, logger configuration and main API routes."""
-import sys
 from typing import Any
 
 import llama_index
 from fastapi import FastAPI
 from fastapi.openapi.utils import get_openapi
-from loguru import logger
 
 from private_gpt.paths import docs_path
 from private_gpt.server.chat.chat_router import chat_router
@@ -16,21 +14,6 @@ from private_gpt.server.health.health_router import health_router
 from private_gpt.server.ingest.ingest_router import ingest_router
 from private_gpt.settings.settings import settings
 
-# Remove pre-configured logging handler
-logger.remove(0)
-# Create a new logging handler same as the pre-configured one but with the extra
-# attribute `request_id`
-logger.add(
-    sys.stdout,
-    level="INFO",
-    format=(
-        "<green>{time:YYYY-MM-DD HH:mm:ss.SSS}</green> | "
-        "<level>{level: <8}</level> | "
-        "<cyan>{name}</cyan>:<cyan>{function}</cyan>:<cyan>{line}</cyan> | "
-        "ID: {extra[request_id]} - <level>{message}</level>"
-    ),
-)
-
 # Add LlamaIndex simple observability
 llama_index.set_global_handler("simple")
 

private_gpt/settings/settings_loader.py

@@ -1,4 +1,5 @@
 import functools
+import logging
 import os
 import sys
 from pathlib import Path
@@ -9,6 +10,8 @@ from pydantic.v1.utils import deep_update, unique_list
 from private_gpt.constants import PROJECT_ROOT_PATH
 from private_gpt.settings.yaml import load_yaml_with_envvars
 
+logger = logging.getLogger(__name__)
+
 _settings_folder = os.environ.get("PGPT_SETTINGS_FOLDER", PROJECT_ROOT_PATH)
 
 # if running in unittest, use the test profile
@@ -41,7 +44,7 @@ def load_profile(profile: str) -> dict[str, Any]:
 
 def load_active_profiles() -> dict[str, Any]:
     """Load active profiles and merge them."""
-    print(f"Starting application with profiles: {active_profiles}")
+    logger.info("Starting application with profiles=%s", active_profiles)
     loaded_profiles = [load_profile(profile) for profile in active_profiles]
     merged: dict[str, Any] = functools.reduce(deep_update, loaded_profiles, {})
     return merged

pyproject.toml

@@ -7,7 +7,6 @@ authors = ["Zylon <hi@zylon.ai>"]
 [tool.poetry.dependencies]
 python = ">=3.11,<3.12"
 fastapi = { extras = ["all"], version = "^0.103.1" }
-loguru = "^0.7.2"
 boto3 = "^1.28.56"
 injector = "^0.21.0"
 pyyaml = "^6.0.1"