From 64c5ae214a9520151c9c2d52ece535867d799367 Mon Sep 17 00:00:00 2001 From: lopagela Date: Sun, 29 Oct 2023 19:11:02 +0100 Subject: [PATCH] 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 --- poetry.lock | 34 +------------------ private_gpt/__init__.py | 10 ++++++ private_gpt/__main__.py | 5 ++- .../components/llm/custom/sagemaker.py | 5 ++- private_gpt/main.py | 17 ---------- private_gpt/settings/settings_loader.py | 5 ++- pyproject.toml | 1 - 7 files changed, 23 insertions(+), 54 deletions(-) diff --git a/poetry.lock b/poetry.lock index 4b36f6fe..6739a3a1 100644 --- a/poetry.lock +++ b/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" diff --git a/private_gpt/__init__.py b/private_gpt/__init__.py index dd7fcef4..1f409831 100644 --- a/private_gpt/__init__.py +++ b/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) diff --git a/private_gpt/__main__.py b/private_gpt/__main__.py index 100dfdc3..6bf2f156 100644 --- a/private_gpt/__main__.py +++ b/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) diff --git a/private_gpt/components/llm/custom/sagemaker.py b/private_gpt/components/llm/custom/sagemaker.py index 08f56a95..070f8ed6 100644 --- a/private_gpt/components/llm/custom/sagemaker.py +++ b/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"]) diff --git a/private_gpt/main.py b/private_gpt/main.py index 7a6dc66b..f5f193e2 100644 --- a/private_gpt/main.py +++ b/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=( - "{time:YYYY-MM-DD HH:mm:ss.SSS} | " - "{level: <8} | " - "{name}:{function}:{line} | " - "ID: {extra[request_id]} - {message}" - ), -) - # Add LlamaIndex simple observability llama_index.set_global_handler("simple") diff --git a/private_gpt/settings/settings_loader.py b/private_gpt/settings/settings_loader.py index d4b3d55c..99c2ca40 100644 --- a/private_gpt/settings/settings_loader.py +++ b/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 diff --git a/pyproject.toml b/pyproject.toml index 7ac73305..bc1d075b 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -7,7 +7,6 @@ authors = ["Zylon "] [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"