diff --git a/README.md b/README.md
index 2d2bf93..59c4164 100644
--- a/README.md
+++ b/README.md
@@ -139,14 +139,15 @@ Here is what every option means:
| ------------------------- | :-------: | :-----------------------------------: | :----------: | --------------------------------------------------------------- |
| `CONF_updateInterval` | `int` | | **required** | Update intervall in seconds. |
| `CONF_babelLocale` | `string` | | **required** | Select your country from this [list](https://www.ibm.com/docs/en/radfws/9.7?topic=overview-locales-code-pages-supported). "Locale name" is the column you need! |
-| `CONF_mqtt` | `json` | `broker` | **required** | Your MQTT Broker IP. Eg. 192.168.0.5.
+| `CONF_mqtt` | `json` | `broker` | **required** | Your MQTT Broker IP. Eg. 192.168.0.5. |
| `CONF_mqtt` | `json` | `port` | 1883 | Your MQTT Broker Port. If no value is given, port 1883 will be used. |
-| `CONF_mqtt` | `json` | `username` | optional | MQTT Username for your broker.
-| `CONF_mqtt` | `json` | `password` | optional | MQTT Password for your broker.
-| `CONF_volvoData` | `json` | `username` | **required** | Normally your email address to login into the Volvo App.
-| `CONF_volvoData` | `json` | `password` | **required** | Your password to login into the Volvo App.
-| `CONF_volvoData` | `json` | `vin` | optional | A single VIN like "VIN1" or a list of VINs like "["VIN1", "VIN2"]". Leave this empty if you don't know your VIN. The addon will use every car that is tied to your account.
-| `CONF_volvoData` | `json` | `vccapikey` | **required** | VCCAPIKEY linked with your volvo developer account. Get your Vccapi key from [here](https://developer.volvocars.com/account/). Starting version 1.8.0, it is possible to define multiple keys, like this: `["vccapikey1", "vccapikey2", "vccapikey3", "etc..."]`
+| `CONF_mqtt` | `json` | `username` | optional | MQTT Username for your broker. |
+| `CONF_mqtt` | `json` | `password` | optional | MQTT Password for your broker. |
+| `CONF_mqtt` | `json` | `logging` | optional | Enable MQTT logging (true/false). Default don't enable MQTT log. |
+| `CONF_volvoData` | `json` | `username` | **required** | Normally your email address to login into the Volvo App. |
+| `CONF_volvoData` | `json` | `password` | **required** | Your password to login into the Volvo App. |
+| `CONF_volvoData` | `json` | `vin` | optional | A single VIN like "VIN1" or a list of VINs like "["VIN1", "VIN2"]". Leave this empty if you don't know your VIN. The addon will use every car that is tied to your account. |
+| `CONF_volvoData` | `json` | `vccapikey` | **required** | VCCAPIKEY linked with your volvo developer account. Get your Vccapi key from [here](https://developer.volvocars.com/account/). Starting version 1.8.0, it is possible to define multiple keys, like this: `["vccapikey1", "vccapikey2", "vccapikey3", "etc..."]` |
| `CONF_debug` | `string` | | optional | Debug option (true/false). Normally you don't need this. |
| `TZ` | `string` | | **required** | Container timezone eg "Europe/Berlin" from [here](https://docs.diladele.com/docker/timezones.html)|
diff --git a/src/mqtt.py b/src/mqtt.py
index ec598a4..5744a60 100644
--- a/src/mqtt.py
+++ b/src/mqtt.py
@@ -6,6 +6,7 @@
import util
import os
import requests
+import threading
from threading import Thread, Timer
from datetime import datetime
from babel.dates import format_datetime
@@ -27,6 +28,14 @@ def connect():
client = mqtt.Client("volvoAAOS2mqtt") if os.environ.get("IS_HA_ADDON") \
else mqtt.Client("volvoAAOS2mqtt_" + settings.volvoData["username"].replace("+", ""))
+ if "logging" in settings["mqtt"] and settings["mqtt"]["logging"]:
+ mqtt_logger = logging.getLogger("mqtt")
+ client.enable_logger(mqtt_logger)
+
+ client.on_message = safe_on_message
+ client.on_disconnect = on_disconnect
+ client.on_connect = on_connect
+
client.will_set(availability_topic, "offline", 0, False)
if settings["mqtt"]["username"] and settings["mqtt"]["password"]:
client.username_pw_set(settings["mqtt"]["username"], settings["mqtt"]["password"])
@@ -37,11 +46,9 @@ def connect():
if conf_port > 0:
port = settings["mqtt"]["port"]
client.connect(settings["mqtt"]["broker"], port)
+
client.loop_start()
client.subscribe("volvoAAOS2mqtt/otp_code")
- client.on_message = on_message
- client.on_disconnect = on_disconnect
- client.on_connect = on_connect
global mqtt_client
mqtt_client = client
@@ -51,7 +58,7 @@ def create_otp_input():
state_topic = otp_mqtt_topic + "/state"
config = {
"name": "Volvo OTP",
- "object_id": f"volvo_otp",
+ "object_id": "volvo_otp",
"schema": "state",
"command_topic": otp_mqtt_topic,
"state_topic": state_topic,
@@ -128,6 +135,10 @@ def send_car_images(vin, data, device):
def on_connect(client, userdata, flags, rc):
+ # set a better name for the mqtt_loop Thread
+ threading.current_thread().name = 'mqtt_thread'
+ logging.info("MQTT connected")
+
send_heartbeat()
if len(subscribed_topics) > 0:
for topic in subscribed_topics:
@@ -135,9 +146,16 @@ def on_connect(client, userdata, flags, rc):
def on_disconnect(client, userdata, rc):
- logging.warning("MQTT disconnected, reconnecting automatically")
+ logging.warning(f"MQTT disconnected, reconnecting automatically rc={rc}")
+def safe_on_message(client, userdata, msg):
+ try:
+ on_message(client, userdata, msg)
+ except Exception as error:
+ logging.error(f"Exception {error} processing received message on topic {msg.topic}")
+ return None
+
def on_message(client, userdata, msg):
payload = msg.payload.decode("UTF-8")
if msg.topic == otp_mqtt_topic:
@@ -152,7 +170,7 @@ def on_message(client, userdata, msg):
try:
vin = msg.topic.split('/')[2].split('_')[0]
except IndexError:
- logging.error("Error - Cannot get vin from MQTT topic!")
+ logging.error(f"Error - Cannot get vin from MQTT topic : {msg.topic}!")
return None
if "climate_status" in msg.topic:
@@ -169,17 +187,20 @@ def on_message(client, userdata, msg):
if payload == "PRESS":
update_car_data(True)
elif "update_interval" in msg.topic:
- update_interval = int(payload)
- if update_interval >= 60 or update_interval == -1:
- settings.update({"updateInterval": int(update_interval)})
- else:
- logging.warning("Interval " + str(update_interval) + " seconds is to low. Doing nothing!")
- update_car_data()
+ try:
+ update_interval = int(payload)
+ if update_interval >= 60 or update_interval == -1:
+ settings.update({"updateInterval": int(update_interval)})
+ else:
+ logging.warning(f"Interval {update_interval} seconds is to low. Doing nothing!")
+ update_car_data()
+ except ValueError as error:
+ logging.error(f"Unable to change update_interval {error} payload={payload}")
elif "schedule" in msg.topic:
try:
d = json.loads(payload)
except ValueError as e:
- logging.error("Can't set timer. Error: " + str(e))
+ logging.error(f"Can't set timer. Error: {e}, payload={payload}")
return None
if d["mode"] == "timer":
@@ -197,13 +218,13 @@ def start_climate_timer(d, vin):
start_datetime = local_datetime.replace(hour=hour, minute=minute, second=0)
timer_seconds = (start_datetime - local_datetime).total_seconds()
except Exception as e:
- logging.error("Error creating climate timer: " + str(e))
+ logging.error(f"Error creating climate timer: {e}")
return None
if timer_seconds > 0:
Timer(timer_seconds, activate_climate_timer, (vin, start_datetime.isoformat(),)).start()
active_schedules[vin]["timers"].append(start_datetime.isoformat())
- logging.debug("Climate timer set to " + str(start_datetime))
+ logging.debug(f"Climate timer set to {start_datetime}")
update_car_data()
else:
logging.warning("Timer can not be set. Unusable start time entered")
@@ -211,28 +232,28 @@ def start_climate_timer(d, vin):
def unlock_car(vin):
# Start the api call in another thread for HA performance
- Thread(target=volvo.api_call, args=(CAR_UNLOCK_URL, "POST", vin)).start()
+ Thread(target=volvo.api_call, args=(CAR_UNLOCK_URL, "POST", vin), name="unlock_car_thread").start()
# Force set unlocking state
update_car_data(False, {"entity_id": "lock_status", "vin": vin, "state": "UNLOCKING"})
# Fetch API lock state until unlocking finished
- Thread(target=volvo.check_lock_status, args=(vin, "LOCKED")).start()
+ Thread(target=volvo.check_lock_status, args=(vin, "LOCKED"), name="check_lock_status_thread").start()
def lock_car(vin):
# Start the api call in another thread for HA performance
- Thread(target=volvo.api_call, args=(CAR_LOCK_URL, "POST", vin)).start()
+ Thread(target=volvo.api_call, args=(CAR_LOCK_URL, "POST", vin), name="lock_car_thread").start()
# Force set locking state
update_car_data(False, {"entity_id": "lock_status", "vin": vin, "state": "LOCKING"})
# Fetch API lock state until locking finished
- Thread(target=volvo.check_lock_status, args=(vin, "UNLOCKED")).start()
+ Thread(target=volvo.check_lock_status, args=(vin, "UNLOCKED"), name="check_lock_status_thread").start()
def stop_climate(vin):
global assumed_climate_state, climate_timer, engine_status
# Start the api call in another thread for HA performance
- Thread(target=volvo.api_call, args=(CLIMATE_STOP_URL, "POST", vin)).start()
+ Thread(target=volvo.api_call, args=(CLIMATE_STOP_URL, "POST", vin), name="stop_climate_thread").start()
# Stop door check thread if running
if engine_status[vin].is_alive():
@@ -256,10 +277,10 @@ def activate_climate_timer(vin, start_time):
def start_climate(vin):
global assumed_climate_state, climate_timer, engine_status
# Start the api call in another thread for HA performance
- Thread(target=volvo.api_call, args=(CLIMATE_START_URL, "POST", vin)).start()
+ Thread(target=volvo.api_call, args=(CLIMATE_START_URL, "POST", vin), name="start_climate_thread").start()
# Start door check thread to turn off climate if driver door is opened
- check_engine_thread = Thread(target=volvo.check_engine_status, args=(vin,))
+ check_engine_thread = Thread(target=volvo.check_engine_status, args=(vin,), name="check_engine_status_thread")
check_engine_thread.start()
engine_status[vin] = check_engine_thread
@@ -277,9 +298,12 @@ def update_loop():
while True:
if settings["updateInterval"] > 0:
logging.info("Sending mqtt update...")
- send_heartbeat()
- update_car_data()
- logging.info("Mqtt update done. Next run in " + str(settings["updateInterval"]) + " seconds.")
+ try:
+ send_heartbeat()
+ update_car_data()
+ logging.info(f"Mqtt update done. Next run in {settings['updateInterval']} seconds.")
+ except Exception as error:
+ logging.info(f"Exception {error} in Mqtt update. Next run in {settings['updateInterval']} seconds.")
time.sleep(settings["updateInterval"])
else:
logging.info("Data update is disabled, doing nothing for 30 seconds")
@@ -338,6 +362,7 @@ def update_car_data(force_update=False, overwrite={}):
else:
topic = f"homeassistant/{entity['domain']}/{vin}_{entity['id']}/state"
+ logging.info(f"update_car_data {topic} {state}")
if state or state == 0:
mqtt_client.publish(
topic,
diff --git a/src/util.py b/src/util.py
index e088943..d1dc9ba 100644
--- a/src/util.py
+++ b/src/util.py
@@ -71,7 +71,7 @@ def setup_logging():
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',
+ '%(asctime)s volvo2mqtt [%(threadName)s] [%(process)d] - %(levelname)s: %(message)s',
'%b %d %H:%M:%S')
file_log_handler.setFormatter(formatter)
diff --git a/src/volvo.py b/src/volvo.py
index 5c0242b..f3e05a8 100644
--- a/src/volvo.py
+++ b/src/volvo.py
@@ -47,6 +47,7 @@ def authorize(renew_tokenfile=False):
except ValueError:
logging.warning("Detected corrupted token file, restarting auth process")
authorize(True)
+ return
else:
logging.info("Starting login with OTP")
auth_session = requests.session()
@@ -105,7 +106,7 @@ def authorize(renew_tokenfile=False):
get_vcc_api_keys()
get_vehicles()
check_supported_endpoints()
- Thread(target=backend_status_loop).start()
+ Thread(target=backend_status_loop,name="backend_status_thread").start()
def continue_auth(auth_session, data):
next_url = data["_links"]["continueAuthentication"]["href"] + "?action=continueAuthentication"
@@ -198,7 +199,11 @@ def refresh_auth():
global token_expires_at
token_expires_at = datetime.now(util.TZ) + timedelta(seconds=(data["expires_in"] - 30))
refresh_token = data["refresh_token"]
+ elif int(auth.status_code / 100) == 5:
+ # Server error try again later
+ logging.warning("Refreshing credentials failed!: " + str(auth.status_code) + " Message: " + auth.text)
else:
+ # TODO check other codes that dont have to force the renew_tokenfile
logging.warning("Refreshing credentials failed!: " + str(auth.status_code) + " Message: " + auth.text)
authorize(renew_tokenfile=True)
@@ -438,27 +443,38 @@ def check_engine_status(vin):
def backend_status_loop():
+ logging.debug("backend_status_loop started")
while True:
- get_backend_status()
- # Update every hour
- time.sleep(3600)
+ last_status = get_backend_status()
+ # Update every hour when not error, 10 minutes when got server error
+ time.sleep(3600 if not last_status.startswith("APIERR_") else 600)
def get_backend_status():
global backend_status
- response = session.get(API_BACKEND_STATUS, timeout=15)
try:
- data = response.json()
- if util.keys_exists(data, "message"):
- if data["message"]:
- backend_status = data["message"]
+ response = session.get(API_BACKEND_STATUS, timeout=15)
+ try:
+ data = response.json()
+ if util.keys_exists(data, "message"):
+ if data["message"]:
+ backend_status = data["message"]
+ else:
+ backend_status = "NO_WARNING"
else:
backend_status = "NO_WARNING"
- else:
- backend_status = "NO_WARNING"
- except JSONDecodeError as e:
- backend_status = "NO_WARNING"
+ except JSONDecodeError as e:
+ logging.error(f"Invalid json response from API Backend Status - {response} - {e}")
+ backend_status = "APIERR_INVALID_JSON_RESPONSE"
+
+ except requests.exceptions.ReadTimeout as e:
+ logging.error(f"API Backend Status - timeout - {e}")
+ backend_status = "APIERR_TIMEOUT"
+ except requests.exceptions.RequestException as e:
+ logging.error(f"API Backend Status - Error - {e}")
+ backend_status = "APIERR_REQUEST_ERROR"
+
return backend_status
@@ -474,28 +490,28 @@ def api_call(url, method, vin, sensor_id=None, force_update=False, key_change=Fa
# Exception caught while getting data from volvo api, doing nothing
return None
elif method == "GET":
- logging.debug("Starting " + method + " call against " + url)
+ logging.debug(f"Starting {method} call against {url}")
try:
response = session.get(url.format(vin), timeout=15)
except requests.exceptions.RequestException as e:
- logging.error("Error getting data: " + str(e))
+ logging.error(f"Error getting data: {e} from {url}")
return None
elif method == "POST":
- logging.debug("Starting " + method + " call against " + url)
+ logging.debug(f"Starting {method} call against {url}")
try:
response = session.post(url.format(vin), timeout=20)
except requests.exceptions.RequestException as e:
- logging.error("Error getting data: " + str(e))
+ logging.error(f"Error getting data from {url} : {e}")
return None
else:
- logging.error("Unkown method posted: " + method + ". Returning nothing")
+ logging.error(f"Unkown method posted: {method}. Returning nothing")
return None
- logging.debug("Response status code: " + str(response.status_code))
+ logging.debug(f"Response status code: {response.status_code}")
try:
data = response.json()
except JSONDecodeError as e:
- logging.error("Fetched json decode error, Volvo API seems to return garbage. Skipping update. Error: " + str(e))
+ logging.error(f"Fetched json decode error, Volvo API seems to return garbage. Skipping update. Error: {e}")
return None
if response.status_code == 200:
@@ -518,9 +534,9 @@ def api_call(url, method, vin, sensor_id=None, force_update=False, key_change=Fa
api_call(url, method, vin, sensor_id, force_update, True)
else:
logging.error(
- "API Call failed. Status Code: " + str(response.status_code) + ". Error: " + response.text)
+ f"API Call failed to {url}. Status Code: {response.status_code}. Error: {response.text}")
else:
- logging.error("API Call failed. Status Code: " + str(response.status_code) + ". Error: " + response.text)
+ logging.error(f"API Call failed to {url}. Status Code: {response.status_code}. Error: {response.text}")
return None
@@ -528,11 +544,11 @@ def cached_request(url, method, vin, force_update=False, key_change=False):
global cached_requests
if not util.keys_exists(cached_requests, vin + "_" + url):
# No API Data cached, get fresh data from API
- logging.debug("Starting " + method + " call against " + url)
+ logging.debug(f"Starting {method} call against {url}")
try:
response = session.get(url.format(vin), timeout=15)
except requests.exceptions.RequestException as e:
- logging.error("Error getting data: " + str(e))
+ logging.error(f"Error getting data from {url}: {e}")
return None
data = {"response": response, "last_update": datetime.now(util.TZ)}
@@ -544,11 +560,11 @@ def cached_request(url, method, vin, force_update=False, key_change=False):
"last_update"]).total_seconds() >= 2) \
or key_change:
# Old Data in Cache, or force mode active, updating
- logging.debug("Starting " + method + " call against " + url)
+ logging.debug(f"Starting {method} call against {url}")
try:
response = session.get(url.format(vin), timeout=15)
except requests.exceptions.RequestException as e:
- logging.error("Error getting data: " + str(e))
+ logging.error(f"Error getting data from {url} : {e}")
return None
data = {"response": response, "last_update": datetime.now(util.TZ)}
cached_requests[vin + "_" + url] = data