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 4b36f6feb..6739a3a18 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 dd7fcef4b..1f409831e 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 100dfdc38..6bf2f156e 100644 --- a/private_gpt/__main__.py +++ b/private_gpt/__main__.py @@ -5,4 +5,7 @@ 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 08f56a955..070f8ed67 100644 --- a/private_gpt/components/llm/custom/sagemaker.py +++ b/private_gpt/components/llm/custom/sagemaker.py @@ -3,6 +3,7 @@ import io import json +import logging from typing import TYPE_CHECKING, Any import boto3 # type: ignore @@ -26,6 +27,8 @@ CompletionResponseGen, ) +logger = logging.getLogger(__name__) + class LineIterator: r"""A helper class for parsing the byte stream input from TGI container. @@ -81,7 +84,7 @@ def __next__(self) -> Any: 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 7a6dc66b6..f5f193e2f 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.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 d4b3d55ce..99c2ca407 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 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 7ac733052..bc1d075bd 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"