From 4748f70c0085beaa3026530b551423b5c7162252 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sun, 4 Feb 2024 22:39:32 +0100 Subject: [PATCH 1/9] Add basic logging based on logfmt --- README.md | 7 ++++-- docker-compose.yml | 1 + requirements.txt | 3 ++- src/functions.py | 62 ++++++++++++++++++++++++++++------------------ src/main.py | 29 +++++++++++++++++++--- 5 files changed, 71 insertions(+), 31 deletions(-) diff --git a/README.md b/README.md index 8ba8923..ddfbc2f 100644 --- a/README.md +++ b/README.md @@ -84,8 +84,8 @@ possible as well. All the settings are optional. Keep in mind that when you choose a cache type that you will need to set the corresponding cache settings for that type as well -(ex.: `REDIS_HOST`, `REDIS_PORT`, `REDIS_PASSWORD` is required when using the -**redis** type). +(ex.: `REDIS_HOST`, `REDIS_PORT`, `REDIS_PASSWORD` or `REDIS_URL` is required +when using the **redis** type). All the available options in an `.env` file: ``` @@ -106,6 +106,9 @@ REDIS_PASSWORD="YourRedisP@ssword!" # (see: https://redis-py.readthedocs.io/en/stable/#quickly-connecting-to-redis) REDIS_URL="redis://YourUsername:YourRedisP@ssword!@your.redis.host.example.com:6379" +# logging +LOG_LEVEL=info + # deta DETA_BASE_NAME="steamcmd" DETA_PROJECT_KEY="YourDet@ProjectKey!" diff --git a/docker-compose.yml b/docker-compose.yml index 893b3e3..ced60e5 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -16,6 +16,7 @@ services: CACHE_EXPIRATION: 120 REDIS_HOST: redis REDIS_PORT: 6379 + LOG_LEVEL: info PYTHONUNBUFFERED: "TRUE" restart: always redis: diff --git a/requirements.txt b/requirements.txt index 786cbc2..10495dc 100644 --- a/requirements.txt +++ b/requirements.txt @@ -2,8 +2,9 @@ fastapi redis deta -python-dotenv semver +python-dotenv +logfmter steam[client] gevent diff --git a/src/functions.py b/src/functions.py index 694ec19..ec6d2ba 100644 --- a/src/functions.py +++ b/src/functions.py @@ -3,7 +3,7 @@ """ # import modules -import os, json, gevent, datetime, redis +import os, json, gevent, datetime, redis, logging from steam.client import SteamClient from deta import Deta @@ -13,6 +13,8 @@ def app_info(app_id): connect_timeout = 5 current_time = str(datetime.datetime.now()) + logging.info("Started requesting app info", extra={"app_id": app_id}) + try: # Sometimes it hangs for 30+ seconds. Normal connection takes about 500ms for _ in range(connect_retries): @@ -21,34 +23,32 @@ def app_info(app_id): try: with gevent.Timeout(connect_timeout): - print("Connecting via steamclient") - print( - "Retrieving app info for: " - + str(app_id) - + ", retry count: " - + count - ) + logging.info("Retrieving app info from steamclient", extra={"app_id": app_id, "retry_count": count}) + logging.debug("Connecting via steamclient to steam api") client = SteamClient() client.anonymous_login() client.verbose_debug = False + + logging.debug("Requesting app info from steam api") info = client.get_product_info(apps=[app_id], timeout=1) return info except gevent.timeout.Timeout: + logging.warning("Encountered timeout when trying to connect to steam api. Retrying..") client._connecting = False else: - print("Succesfully retrieved app info for app id: " + str(app_id)) + logging.info("Succesfully retrieved app info", extra={"app_id": app_id}) break else: + logging.error("Max connect retries exceeded", extra={"connect_retries": connect_retries}) raise Exception(f"Max connect retries ({connect_retries}) exceeded") except Exception as err: - print("Failed in retrieving app info for app id: " + str(app_id)) - print(err) - + logging.error("Failed in retrieving app info", extra={"app_id": app_id}) + logging.error(err, extra={"app_id": app_id}) def cache_read(app_id): """ @@ -61,7 +61,7 @@ def cache_read(app_id): return deta_read(app_id) else: # print query parse error and return empty dict - print("Incorrect set cache type: " + os.environ["CACHE_TYPE"]) + logging.error("Set incorrect cache type", extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}) # return failed status return False @@ -78,7 +78,7 @@ def cache_write(app_id, data): return deta_write(app_id, data) else: # print query parse error and return empty dict - print("Incorrect set cache type: " + os.environ["CACHE_TYPE"]) + logging.error("Set incorrect cache type", extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}) # return failed status return False @@ -130,13 +130,10 @@ def redis_read(app_id): # return cached data return data - except Exception as read_error: + except Exception as redis_error: # print query parse error and return empty dict - print( - "The following error occured while trying to read and decode " - + "from Redis cache: \n > " - + str(read_error) - ) + logging.error("An error occured while trying to read and decode from Redis cache", extra={"app_id": app_id, "error_msg": redis_error}) + # return failed status return False @@ -162,15 +159,32 @@ def redis_write(app_id, data): except Exception as redis_error: # print query parse error and return empty dict - print( - "The following error occured while trying to write to Redis cache: \n > " - + str(redis_error) - ) + logging.error("An error occured while trying to write to Redis cache", extra={"app_id": app_id, "error_msg": redis_error}) # return fail status return False +def log_level(level): + """ + Sets lowest level to log. + """ + + match level: + case "debug": + logging.getLogger().setLevel(logging.DEBUG) + case "info": + logging.getLogger().setLevel(logging.INFO) + case "warning": + logging.getLogger().setLevel(logging.WARNING) + case "error": + logging.getLogger().setLevel(logging.ERROR) + case "critical": + logging.getLogger().setLevel(logging.CRITICAL) + case _: + logging.getLogger().setLevel(logging.WARNING) + + def deta_read(app_id): """ Read app info from Deta base cache. diff --git a/src/main.py b/src/main.py index 2114f69..e97b377 100644 --- a/src/main.py +++ b/src/main.py @@ -6,17 +6,28 @@ from deta import Deta from typing import Union from fastapi import FastAPI, Response, status -from functions import app_info, cache_read, cache_write -import os, datetime, json, semver, typing +from functions import app_info, cache_read, cache_write, log_level +import os, datetime, json, semver, typing, logging, logfmter +from logfmter import Logfmter # load configuration from dotenv import load_dotenv - load_dotenv() # initialise app app = FastAPI() +# set logformat +formatter = Logfmter( + keys=["level"], + mapping={"level": "levelname"} +) +handler = logging.StreamHandler() +handler.setFormatter(formatter) +logging.basicConfig(handlers=[handler]) + +if "LOG_LEVEL" in os.environ: + log_level(os.environ["LOG_LEVEL"]) # include "pretty" for backwards compatibility class PrettyJSONResponse(Response): @@ -35,26 +46,35 @@ def render(self, content: typing.Any) -> bytes: @app.get("/v1/info/{app_id}", response_class=PrettyJSONResponse) def read_app(app_id: int, pretty: bool = False): + + logging.info("Requested app info", extra={"app_id": app_id}) + if "CACHE" in os.environ and os.environ["CACHE"]: info = cache_read(app_id) if not info: - print("App info: " + str(app_id) + " could not be find in the cache") + logging.info("App info could not be found in cache", extra={"app_id": app_id}) info = app_info(app_id) cache_write(app_id, info) + else: + logging.info("App info was succesfully retrieved from cache", extra={"app_id": app_id}) else: info = app_info(app_id) if not info["apps"]: + logging.info("No app has been found at Steam but the request was succesfull", extra={"app_id": app_id}) # return empty result for not found app return {"data": {app_id: {}}, "status": "success", "pretty": pretty} + logging.info("Succesfully retrieved app info", extra={"app_id": app_id}) return {"data": info["apps"], "status": "success", "pretty": pretty} @app.get("/v1/version", response_class=PrettyJSONResponse) def read_item(pretty: bool = False): + logging.info("Requested api version") + # check if version succesfully read and parsed if "VERSION" in os.environ and os.environ["VERSION"]: return { @@ -63,6 +83,7 @@ def read_item(pretty: bool = False): "pretty": pretty, } else: + logging.warning("No version has been defined and could therefor not satisfy the request") return { "status": "error", "data": "Something went wrong while retrieving and parsing the current API version. Please try again later", From 8b014d0bf8e2b777a48f657b2fb0a3ef1ab6e4e3 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sun, 4 Feb 2024 22:42:25 +0100 Subject: [PATCH 2/9] Add black formatting --- src/functions.py | 35 ++++++++++++++++++++++++++++------- src/main.py | 26 +++++++++++++++++--------- 2 files changed, 45 insertions(+), 16 deletions(-) diff --git a/src/functions.py b/src/functions.py index ec6d2ba..d0e4f8e 100644 --- a/src/functions.py +++ b/src/functions.py @@ -23,7 +23,10 @@ def app_info(app_id): try: with gevent.Timeout(connect_timeout): - logging.info("Retrieving app info from steamclient", extra={"app_id": app_id, "retry_count": count}) + logging.info( + "Retrieving app info from steamclient", + extra={"app_id": app_id, "retry_count": count}, + ) logging.debug("Connecting via steamclient to steam api") client = SteamClient() @@ -36,20 +39,26 @@ def app_info(app_id): return info except gevent.timeout.Timeout: - logging.warning("Encountered timeout when trying to connect to steam api. Retrying..") + logging.warning( + "Encountered timeout when trying to connect to steam api. Retrying.." + ) client._connecting = False else: logging.info("Succesfully retrieved app info", extra={"app_id": app_id}) break else: - logging.error("Max connect retries exceeded", extra={"connect_retries": connect_retries}) + logging.error( + "Max connect retries exceeded", + extra={"connect_retries": connect_retries}, + ) raise Exception(f"Max connect retries ({connect_retries}) exceeded") except Exception as err: logging.error("Failed in retrieving app info", extra={"app_id": app_id}) logging.error(err, extra={"app_id": app_id}) + def cache_read(app_id): """ Read app info from chosen cache. @@ -61,7 +70,10 @@ def cache_read(app_id): return deta_read(app_id) else: # print query parse error and return empty dict - logging.error("Set incorrect cache type", extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}) + logging.error( + "Set incorrect cache type", + extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}, + ) # return failed status return False @@ -78,7 +90,10 @@ def cache_write(app_id, data): return deta_write(app_id, data) else: # print query parse error and return empty dict - logging.error("Set incorrect cache type", extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}) + logging.error( + "Set incorrect cache type", + extra={"app_id": app_id, "cache_type": os.environ["CACHE_TYPE"]}, + ) # return failed status return False @@ -132,7 +147,10 @@ def redis_read(app_id): except Exception as redis_error: # print query parse error and return empty dict - logging.error("An error occured while trying to read and decode from Redis cache", extra={"app_id": app_id, "error_msg": redis_error}) + logging.error( + "An error occured while trying to read and decode from Redis cache", + extra={"app_id": app_id, "error_msg": redis_error}, + ) # return failed status return False @@ -159,7 +177,10 @@ def redis_write(app_id, data): except Exception as redis_error: # print query parse error and return empty dict - logging.error("An error occured while trying to write to Redis cache", extra={"app_id": app_id, "error_msg": redis_error}) + logging.error( + "An error occured while trying to write to Redis cache", + extra={"app_id": app_id, "error_msg": redis_error}, + ) # return fail status return False diff --git a/src/main.py b/src/main.py index e97b377..8c524e8 100644 --- a/src/main.py +++ b/src/main.py @@ -12,16 +12,14 @@ # load configuration from dotenv import load_dotenv + load_dotenv() # initialise app app = FastAPI() # set logformat -formatter = Logfmter( - keys=["level"], - mapping={"level": "levelname"} -) +formatter = Logfmter(keys=["level"], mapping={"level": "levelname"}) handler = logging.StreamHandler() handler.setFormatter(formatter) logging.basicConfig(handlers=[handler]) @@ -29,6 +27,7 @@ if "LOG_LEVEL" in os.environ: log_level(os.environ["LOG_LEVEL"]) + # include "pretty" for backwards compatibility class PrettyJSONResponse(Response): media_type = "application/json" @@ -46,24 +45,31 @@ def render(self, content: typing.Any) -> bytes: @app.get("/v1/info/{app_id}", response_class=PrettyJSONResponse) def read_app(app_id: int, pretty: bool = False): - logging.info("Requested app info", extra={"app_id": app_id}) if "CACHE" in os.environ and os.environ["CACHE"]: info = cache_read(app_id) if not info: - logging.info("App info could not be found in cache", extra={"app_id": app_id}) + logging.info( + "App info could not be found in cache", extra={"app_id": app_id} + ) info = app_info(app_id) cache_write(app_id, info) else: - logging.info("App info was succesfully retrieved from cache", extra={"app_id": app_id}) + logging.info( + "App info was succesfully retrieved from cache", + extra={"app_id": app_id}, + ) else: info = app_info(app_id) if not info["apps"]: - logging.info("No app has been found at Steam but the request was succesfull", extra={"app_id": app_id}) + logging.info( + "No app has been found at Steam but the request was succesfull", + extra={"app_id": app_id}, + ) # return empty result for not found app return {"data": {app_id: {}}, "status": "success", "pretty": pretty} @@ -83,7 +89,9 @@ def read_item(pretty: bool = False): "pretty": pretty, } else: - logging.warning("No version has been defined and could therefor not satisfy the request") + logging.warning( + "No version has been defined and could therefor not satisfy the request" + ) return { "status": "error", "data": "Something went wrong while retrieving and parsing the current API version. Please try again later", From 1a2951d7edc0c635381741c28dc0c9974e6f5765 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Mon, 5 Feb 2024 00:04:30 +0100 Subject: [PATCH 3/9] Minor update to logging output --- src/main.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/main.py b/src/main.py index 8c524e8..4f0cfc4 100644 --- a/src/main.py +++ b/src/main.py @@ -58,7 +58,7 @@ def read_app(app_id: int, pretty: bool = False): cache_write(app_id, info) else: logging.info( - "App info was succesfully retrieved from cache", + "App info succesfully retrieved from cache", extra={"app_id": app_id}, ) From f3f04bd692b71c9886b07c30a2dddfd6c7f8bbfa Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 16:46:23 +0200 Subject: [PATCH 4/9] Decrease timeout and retry count --- src/functions.py | 7 +++---- src/main.py | 8 ++++++++ 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/src/functions.py b/src/functions.py index d0e4f8e..910f49a 100644 --- a/src/functions.py +++ b/src/functions.py @@ -9,8 +9,8 @@ def app_info(app_id): - connect_retries = 3 - connect_timeout = 5 + connect_retries = 2 + connect_timeout = 3 current_time = str(datetime.datetime.now()) logging.info("Started requesting app info", extra={"app_id": app_id}) @@ -18,8 +18,7 @@ def app_info(app_id): try: # Sometimes it hangs for 30+ seconds. Normal connection takes about 500ms for _ in range(connect_retries): - count = _ + 1 - count = str(count) + count = str(_) try: with gevent.Timeout(connect_timeout): diff --git a/src/main.py b/src/main.py index 4f0cfc4..0689003 100644 --- a/src/main.py +++ b/src/main.py @@ -65,6 +65,14 @@ def read_app(app_id: int, pretty: bool = False): else: info = app_info(app_id) + if info == None: + logging.info( + "The SteamCMD backend returned no actual data and failed", + extra={"app_id": app_id}, + ) + # return empty result for not found app + return {"data": {app_id: {}}, "status": "failed", "pretty": pretty} + if not info["apps"]: logging.info( "No app has been found at Steam but the request was succesfull", From 0aff8dcb9ec80048b6272405e59fe431824e0093 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 16:49:22 +0200 Subject: [PATCH 5/9] Remove obsolete version docker compose config --- docker-compose.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/docker-compose.yml b/docker-compose.yml index ced60e5..893a12e 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -1,4 +1,3 @@ -version: '3' services: web: build: . From 56ddd22d6f26b7ec1b28ce25e8ea326a80df3147 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 17:16:01 +0200 Subject: [PATCH 6/9] Move Python tests and linting to ruff --- .github/workflows/test.yml | 13 ++----------- 1 file changed, 2 insertions(+), 11 deletions(-) diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index ea2a9af..8245698 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -22,15 +22,6 @@ jobs: runs-on: ubuntu-22.04 steps: - uses: actions/checkout@v3 - - uses: ricardochaves/python-lint@v1.3.0 + - uses: jpetrucciani/ruff-check@main with: - # python files - python-root-list: "src" - # enabled linters - use-black: true - # disabled linters - use-pylint: false - use-pycodestyle: false - use-flake8: false - use-mypy: false - use-isort: false + path: 'src/' \ No newline at end of file From 1cfbd04b3b09626bc3afa71cafe202aa6e80c0b3 Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 17:26:35 +0200 Subject: [PATCH 7/9] Implement PEP-8 code style improvements --- src/functions.py | 8 ++++++-- src/main.py | 12 +++++++----- 2 files changed, 13 insertions(+), 7 deletions(-) diff --git a/src/functions.py b/src/functions.py index 910f49a..27ae677 100644 --- a/src/functions.py +++ b/src/functions.py @@ -3,7 +3,12 @@ """ # import modules -import os, json, gevent, datetime, redis, logging +import os +import json +import gevent +import datetime +import redis +import logging from steam.client import SteamClient from deta import Deta @@ -11,7 +16,6 @@ def app_info(app_id): connect_retries = 2 connect_timeout = 3 - current_time = str(datetime.datetime.now()) logging.info("Started requesting app info", extra={"app_id": app_id}) diff --git a/src/main.py b/src/main.py index 0689003..d86d0fd 100644 --- a/src/main.py +++ b/src/main.py @@ -3,11 +3,13 @@ """ # import modules -from deta import Deta -from typing import Union -from fastapi import FastAPI, Response, status +import os +import json +import semver +import typing +import logging +from fastapi import FastAPI, Response from functions import app_info, cache_read, cache_write, log_level -import os, datetime, json, semver, typing, logging, logfmter from logfmter import Logfmter # load configuration @@ -65,7 +67,7 @@ def read_app(app_id: int, pretty: bool = False): else: info = app_info(app_id) - if info == None: + if info is None: logging.info( "The SteamCMD backend returned no actual data and failed", extra={"app_id": app_id}, From 1621dc0d5eb40372cc4678afada5b7c463fce30d Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 17:27:37 +0200 Subject: [PATCH 8/9] Remove unused import module --- src/functions.py | 1 - 1 file changed, 1 deletion(-) diff --git a/src/functions.py b/src/functions.py index 27ae677..ff87f51 100644 --- a/src/functions.py +++ b/src/functions.py @@ -6,7 +6,6 @@ import os import json import gevent -import datetime import redis import logging from steam.client import SteamClient From a70d5c3cea57ead401d733b26532f9c54cf7814d Mon Sep 17 00:00:00 2001 From: Jona Koudijs Date: Sat, 27 Jul 2024 17:29:38 +0200 Subject: [PATCH 9/9] Use newer version of checkout action --- .github/workflows/deploy.yml | 8 ++++---- .github/workflows/test.yml | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/.github/workflows/deploy.yml b/.github/workflows/deploy.yml index 3d780cc..5785e6e 100644 --- a/.github/workflows/deploy.yml +++ b/.github/workflows/deploy.yml @@ -20,7 +20,7 @@ jobs: runs-on: ubuntu-22.04 needs: check-requirements steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - name: Parse API Version run: echo "API_VERSION=$(echo $GITHUB_REF | awk -F '/' '{print $NF}' | cut -c 2-)" >> $GITHUB_ENV - name: Docker Login @@ -37,7 +37,7 @@ jobs: name: Update Readme runs-on: ubuntu-22.04 steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - name: Update Docker Hub Description uses: peter-evans/dockerhub-description@v2 env: @@ -50,7 +50,7 @@ jobs: runs-on: ubuntu-22.04 needs: [check-requirements, build-image] steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - uses: superfly/flyctl-actions/setup-flyctl@master - name: Parse API Version run: echo "API_VERSION=$(echo $GITHUB_REF | awk -F '/' '{print $NF}' | cut -c 2-)" >> $GITHUB_ENV @@ -64,7 +64,7 @@ jobs: runs-on: ubuntu-22.04 needs: [check-requirements, build-image] steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - name: Parse API Version run: echo "API_VERSION=$(echo $GITHUB_REF | awk -F '/' '{print $NF}' | cut -c 2-)" >> $GITHUB_ENV - name: Deploy API on Render.com diff --git a/.github/workflows/test.yml b/.github/workflows/test.yml index 8245698..f6bbbc5 100644 --- a/.github/workflows/test.yml +++ b/.github/workflows/test.yml @@ -13,7 +13,7 @@ jobs: name: Test Image runs-on: ubuntu-22.04 steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - name: Build Image run: docker build -t steamcmd/api:latest . @@ -21,7 +21,7 @@ jobs: name: Python Lint runs-on: ubuntu-22.04 steps: - - uses: actions/checkout@v3 + - uses: actions/checkout@v4 - uses: jpetrucciani/ruff-check@main with: path: 'src/' \ No newline at end of file