From 34a0b9b2a74438988893a99dbb710347d30416e0 Mon Sep 17 00:00:00 2001 From: Linus Dietz <45101649+Dielee@users.noreply.github.com> Date: Fri, 30 Jun 2023 11:16:57 +0200 Subject: [PATCH] Optimize logging (#41) * Move print statements to logger * Add external log location for addon usage * Add more detailed logs for debug * Bump version --- .gitignore | 2 ++ src/Dockerfile | 3 ++- src/config.yaml | 4 +++- src/const.py | 2 +- src/main.py | 7 +++++-- src/mqtt.py | 9 +++++---- src/run.sh | 4 ++++ src/util.py | 36 ++++++++++++++++++++++++++++++++++++ src/volvo.py | 47 ++++++++++++++++++++++++----------------------- 9 files changed, 82 insertions(+), 32 deletions(-) create mode 100644 src/run.sh diff --git a/.gitignore b/.gitignore index 6659316..d7a1cc9 100644 --- a/.gitignore +++ b/.gitignore @@ -2,3 +2,5 @@ venv src/settings.dev.json .env +/src/volvo2mqtt.log +/src/volvo2mqtt.log.1 diff --git a/src/Dockerfile b/src/Dockerfile index e69fb68..e12b1e4 100644 --- a/src/Dockerfile +++ b/src/Dockerfile @@ -15,6 +15,7 @@ RUN pip install -r requirements.txt # copy the content of the local src directory to the working directory COPY / . +RUN chmod a+x /volvoAAOS2mqtt/run.sh # command to run on container start -CMD [ "python", "-u", "./main.py" ] +CMD [ "/volvoAAOS2mqtt/run.sh" ] \ No newline at end of file diff --git a/src/config.yaml b/src/config.yaml index fdebd89..7852028 100644 --- a/src/config.yaml +++ b/src/config.yaml @@ -1,10 +1,12 @@ name: "Volvo2Mqtt" description: "Volvo AAOS MQTT bridge" -version: "1.6.1" +version: "1.6.2" slug: "volvo2mqtt" init: false url: "https://github.com/Dielee/volvo2mqtt" apparmor: true +map: + - addons:rw options: updateInterval: 300 babelLocale: null diff --git a/src/const.py b/src/const.py index 54f5fbd..44fd2fe 100644 --- a/src/const.py +++ b/src/const.py @@ -1,6 +1,6 @@ from config import settings -VERSION = "v1.6.1" +VERSION = "v1.6.2" OAUTH_URL = "https://volvoid.eu.volvocars.com/as/token.oauth2" VEHICLES_URL = "https://api.volvocars.com/connected-vehicle/v1/vehicles" diff --git a/src/main.py b/src/main.py index 176dd60..423bfd8 100644 --- a/src/main.py +++ b/src/main.py @@ -1,11 +1,14 @@ +import logging from volvo import authorize from mqtt import update_loop, connect from const import VERSION -from util import set_tz +from util import set_tz, setup_logging + if __name__ == '__main__': - print("Starting volvo2mqtt version " + VERSION) set_tz() + setup_logging() + logging.info("Starting volvo2mqtt version " + VERSION) authorize() connect() update_loop() diff --git a/src/mqtt.py b/src/mqtt.py index 7bdb982..aa306f8 100644 --- a/src/mqtt.py +++ b/src/mqtt.py @@ -1,3 +1,4 @@ +import logging import time import paho.mqtt.client as mqtt import json @@ -48,14 +49,14 @@ def on_connect(client, userdata, flags, rc): def on_disconnect(client, userdata, rc): - print("MQTT disconnected, reconnecting automatically") + logging.warning("MQTT disconnected, reconnecting automatically") def on_message(client, userdata, msg): try: vin = msg.topic.split('/')[2].split('_')[0] except IndexError: - print("Error - Cannot get vin from MQTT topic!") + logging.error("Error - Cannot get vin from MQTT topic!") return None payload = msg.payload.decode("UTF-8") @@ -111,10 +112,10 @@ def on_message(client, userdata, msg): def update_loop(): create_ha_devices() while True: - print("Sending mqtt update...") + logging.info("Sending mqtt update...") send_heartbeat() update_car_data() - print("Mqtt update done. Next run in " + str(settings["updateInterval"]) + " seconds.") + logging.info("Mqtt update done. Next run in " + str(settings["updateInterval"]) + " seconds.") time.sleep(settings["updateInterval"]) diff --git a/src/run.sh b/src/run.sh new file mode 100644 index 0000000..f8fbbff --- /dev/null +++ b/src/run.sh @@ -0,0 +1,4 @@ +#!/bin/bash +export IS_HA_ADDON="true" + +python -u main.py \ No newline at end of file diff --git a/src/util.py b/src/util.py index 39ed9a2..44bc1cf 100644 --- a/src/util.py +++ b/src/util.py @@ -1,11 +1,46 @@ +import logging import pytz import os +import sys +from logging import handlers +from datetime import datetime from const import units from config import settings +from pathlib import Path TZ = None +def setup_logging(): + log_location = "volvo2mqtt.log" + if os.environ.get("IS_HA_ADDON"): + check_existing_folder() + log_location = "/addons/volvo2mqtt/log/volvo2mqtt.log" + + logging.Formatter.converter = lambda *args: datetime.now(tz=TZ).timetuple() + file_log_handler = logging.handlers.RotatingFileHandler(log_location, maxBytes=1000000, backupCount=1) + formatter = logging.Formatter( + '%(asctime)s volvo2mqtt [%(process)d] - %(levelname)s: %(message)s', + '%b %d %H:%M:%S') + file_log_handler.setFormatter(formatter) + logger = logging.getLogger() + + console_log_handler = logging.StreamHandler(sys.stdout) + console_log_handler.setFormatter(formatter) + + logger.addHandler(console_log_handler) + logger.addHandler(file_log_handler) + + logger.setLevel(logging.INFO) + if "debug" in settings: + if settings["debug"]: + logger.setLevel(logging.DEBUG) + + +def check_existing_folder(): + Path("/addons/volvo2mqtt/log/").mkdir(parents=True, exist_ok=True) + + def keys_exists(element, *keys): """" Check if *keys (nested) exists in `element` (dict). @@ -43,3 +78,4 @@ def convert_metric_values(value): return round((float(value) / divider), 2) else: return value + diff --git a/src/volvo.py b/src/volvo.py index 53c089c..fea1f86 100644 --- a/src/volvo.py +++ b/src/volvo.py @@ -1,3 +1,5 @@ +import logging + import requests import mqtt import util @@ -55,7 +57,7 @@ def authorize(): def refresh_auth(): - print("Refreshing credentials") + logging.info("Refreshing credentials") global refresh_token headers = { "authorization": "Basic aDRZZjBiOlU4WWtTYlZsNnh3c2c1WVFxWmZyZ1ZtSWFEcGhPc3kxUENhVXNpY1F0bzNUUjVrd2FKc2U0QVpkZ2ZJZmNMeXc=", @@ -71,7 +73,7 @@ def refresh_auth(): try: auth = requests.post(OAUTH_URL, data=body, headers=headers) except requests.exceptions.RequestException as e: - print("Error refreshing credentials data: " + str(e)) + logging.error("Error refreshing credentials data: " + str(e)) return None if auth.status_code == 200: @@ -110,16 +112,14 @@ def get_vehicles(): raise Exception("No vehicle found, exiting application!") else: initialize_climate(vins) - print("Vin: " + str(vins) + " found!") + logging.info("Vin: " + str(vins) + " found!") def get_vehicle_details(vin): response = session.get(VEHICLE_DETAILS_URL.format(vin), timeout=15) if response.status_code == 200: data = response.json()["data"] - if "debug" in settings: - if settings["debug"]: - print(response.text) + logging.debug(response.text) device = { "identifiers": [f"volvoAAOS2mqtt_{vin}"], "manufacturer": "Volvo", @@ -157,10 +157,10 @@ def check_supported_endpoints(): state = "" if state is not None: - print("Success! " + entity["name"] + " is supported by your vehicle.") + logging.info("Success! " + entity["name"] + " is supported by your vehicle.") supported_endpoints[vin].append(entity) else: - print("Failed, " + entity["name"] + " is unfortunately not supported by your vehicle.") + logging.info("Failed, " + entity["name"] + " is unfortunately not supported by your vehicle.") def initialize_climate(vins): @@ -169,7 +169,7 @@ def initialize_climate(vins): def disable_climate(vin): - print("Turning climate off by timer!") + logging.info("Turning climate off by timer!") mqtt.door_status[vin].do_run = False mqtt.assumed_climate_state[vin] = "OFF" mqtt.update_car_data() @@ -200,38 +200,39 @@ def api_call(url, method, vin, sensor_id=None, force_update=False): # Exception caught while getting data from volvo api, doing nothing return None elif method == "GET": - print("Starting " + method + " call against " + url) + logging.debug("Starting " + method + " call against " + url) try: response = session.get(url.format(vin), timeout=15) except requests.exceptions.RequestException as e: - print("Error getting data: " + str(e)) + logging.error("Error getting data: " + str(e)) return None elif method == "POST": - print("Starting " + method + " call against " + url) + logging.debug("Starting " + method + " call against " + url) try: response = session.post(url.format(vin), timeout=20) except requests.exceptions.RequestException as e: - print("Error getting data: " + str(e)) + logging.error("Error getting data: " + str(e)) return None else: - print("Unkown method posted: " + method + ". Returning nothing") + logging.error("Unkown method posted: " + method + ". Returning nothing") return None + logging.debug("Response status code: " + str(response.status_code)) if response.status_code == 200: data = response.json() - if "debug" in settings: - if settings["debug"]: - print(response.text) + logging.debug(response.text) else: + logging.debug(response.text) if url == CLIMATE_START_URL and response.status_code == 503: - print("Car in use, cannot start pre climatization") + logging.warning("Car in use, cannot start pre climatization") mqtt.assumed_climate_state[vin] = "OFF" mqtt.update_car_data() elif "extended-vehicle" in url and response.status_code == 403: # Suppress 403 errors for unsupported extended-vehicle api cars + logging.debug("Suppressed 403 for extended-vehicle API") return None else: - print("API Call failed. Status Code: " + str(response.status_code) + ". Error: " + response.text) + logging.error("API Call failed. Status Code: " + str(response.status_code) + ". Error: " + response.text) return None return parse_api_data(data, sensor_id) @@ -240,11 +241,11 @@ def cached_request(url, method, vin, force_update=False): global cached_requests if not util.keys_exists(cached_requests, vin + "_" + url): # No API Data cached, get fresh data from API - print("Starting " + method + " call against " + url) + logging.debug("Starting " + method + " call against " + url) try: response = session.get(url.format(vin), timeout=15) except requests.exceptions.RequestException as e: - print("Error getting data: " + str(e)) + logging.error("Error getting data: " + str(e)) return None data = {"response": response, "last_update": datetime.now(util.TZ)} @@ -255,11 +256,11 @@ def cached_request(url, method, vin, force_update=False): (datetime.now(util.TZ) - cached_requests[vin + "_" + url] ["last_update"]).total_seconds() >= 2): # Old Data in Cache, or force mode active, updating - print("Starting " + method + " call against " + url) + logging.debug("Starting " + method + " call against " + url) try: response = session.get(url.format(vin), timeout=15) except requests.exceptions.RequestException as e: - print("Error getting data: " + str(e)) + logging.error("Error getting data: " + str(e)) return None data = {"response": response, "last_update": datetime.now(util.TZ)} cached_requests[vin + "_" + url] = data