Fix Issue #1: Ensure template activation with Module 0 verification

- Add 0.5s delays after Template and Module commands for device processing
- Verify Module=0 (activation) in post-update verification, not just template
- Apply fixes to both template update and device name update code paths
- Enhanced logging for Module operations and verification
- Fixes issue where template was set but not activated, leaving device inoperable
This commit is contained in:
Mike Geppert 2025-10-28 08:39:15 +00:00
parent 8b05031e2e
commit 4d510688ab

View File

@ -1033,10 +1033,10 @@ class TasmotaDiscovery:
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
self.logger.error(f"Error connecting to {name} at {ip}: {str(e)}") self.logger.error(f"Error connecting to {name} at {ip}: {str(e)}")
def check_and_update_template(self, ip, name): def check_and_update_template(self, ip, name):
"""Check and update device template based on config_other settings. """Check and update device template based on config_other settings.
Algorithm: Algorithm:
1. Get the device name from the Configuration/Other page using Status 0 1. Get the device name from the Configuration/Other page using Status 0
2. Get the current template using Template command 2. Get the current template using Template command
@ -1045,11 +1045,11 @@ class TasmotaDiscovery:
5. If the template doesn't match, write the value to the template 5. If the template doesn't match, write the value to the template
6. If no key matches, check if any value matches the template 6. If no key matches, check if any value matches the template
7. If a value match is found, write the key to the device name 7. If a value match is found, write the key to the device name
Args: Args:
ip: The IP address of the device ip: The IP address of the device
name: The name/hostname of the device name: The name/hostname of the device
Returns: Returns:
bool: True if template was updated, False otherwise bool: True if template was updated, False otherwise
""" """
@ -1067,14 +1067,14 @@ class TasmotaDiscovery:
if not config_other: if not config_other:
self.logger.debug(f"{name}: No device_list/config_other settings found in configuration") self.logger.debug(f"{name}: No device_list/config_other settings found in configuration")
return False return False
# Get Status 0 for device name from Configuration/Other page with increased timeout # Get Status 0 for device name from Configuration/Other page with increased timeout
url_status0 = f"http://{ip}/cm?cmnd=Status%200" url_status0 = f"http://{ip}/cm?cmnd=Status%200"
try: try:
self.logger.debug(f"{name}: Getting Status 0 with increased timeout (10 seconds)") self.logger.debug(f"{name}: Getting Status 0 with increased timeout (10 seconds)")
response = requests.get(url_status0, timeout=10) response = requests.get(url_status0, timeout=10)
status0_data = response.json() status0_data = response.json()
# Log the actual response format for debugging # Log the actual response format for debugging
self.logger.debug(f"{name}: Status 0 response: {status0_data}") self.logger.debug(f"{name}: Status 0 response: {status0_data}")
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
@ -1094,22 +1094,22 @@ class TasmotaDiscovery:
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
self.logger.error(f"{name}: Error getting Status 0: {str(e)}") self.logger.error(f"{name}: Error getting Status 0: {str(e)}")
return False return False
# Extract device name from Status 0 response # Extract device name from Status 0 response
device_name = status0_data.get("Status", {}).get("DeviceName", "") device_name = status0_data.get("Status", {}).get("DeviceName", "")
if not device_name: if not device_name:
self.logger.debug(f"{name}: Could not get device name from Status 0") self.logger.debug(f"{name}: Could not get device name from Status 0")
return False return False
self.logger.debug(f"{name}: Device name from Configuration/Other page: {device_name}") self.logger.debug(f"{name}: Device name from Configuration/Other page: {device_name}")
# Get current template with increased timeout # Get current template with increased timeout
url_template = f"http://{ip}/cm?cmnd=Template" url_template = f"http://{ip}/cm?cmnd=Template"
try: try:
self.logger.debug(f"{name}: Getting template with increased timeout (10 seconds)") self.logger.debug(f"{name}: Getting template with increased timeout (10 seconds)")
response = requests.get(url_template, timeout=10) response = requests.get(url_template, timeout=10)
template_data = response.json() template_data = response.json()
# Log the actual response format for debugging # Log the actual response format for debugging
self.logger.debug(f"{name}: Template response: {template_data}") self.logger.debug(f"{name}: Template response: {template_data}")
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
@ -1129,10 +1129,10 @@ class TasmotaDiscovery:
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
self.logger.error(f"{name}: Error getting template: {str(e)}") self.logger.error(f"{name}: Error getting template: {str(e)}")
return False return False
# Extract current template - handle different response formats # Extract current template - handle different response formats
current_template = "" current_template = ""
# Try different possible response formats # Try different possible response formats
if "Template" in template_data: if "Template" in template_data:
current_template = template_data.get("Template", "") current_template = template_data.get("Template", "")
@ -1149,13 +1149,13 @@ class TasmotaDiscovery:
import json import json
current_template = json.dumps(template_data) current_template = json.dumps(template_data)
self.logger.debug(f"{name}: Found template in dict format with NAME, GPIO, FLAG, BASE keys") self.logger.debug(f"{name}: Found template in dict format with NAME, GPIO, FLAG, BASE keys")
if not current_template: if not current_template:
self.logger.debug(f"{name}: Could not get current template from response") self.logger.debug(f"{name}: Could not get current template from response")
return False return False
self.logger.debug(f"{name}: Current template: {current_template}") self.logger.debug(f"{name}: Current template: {current_template}")
# Check if any key in config_other matches the device name # Check if any key in config_other matches the device name
template_updated = False template_updated = False
if device_name in config_other: if device_name in config_other:
@ -1163,13 +1163,15 @@ class TasmotaDiscovery:
template_value = config_other[device_name] template_value = config_other[device_name]
if not template_value or template_value.strip() == "": if not template_value or template_value.strip() == "":
# Value is blank or empty, print message and skip template check # Value is blank or empty, print message and skip template check
self.logger.info(f"{name}: Device name '{device_name}' matches key in config_other, but value is blank or empty") self.logger.info(
f"{name}: Device name '{device_name}' matches key in config_other, but value is blank or empty")
print(f"\nDevice {name} at {ip} must be set manually in Configuration/Module to: {device_name}") print(f"\nDevice {name} at {ip} must be set manually in Configuration/Module to: {device_name}")
print(f"The config_other entry has a blank value for key: {device_name}") print(f"The config_other entry has a blank value for key: {device_name}")
return False return False
elif current_template != template_value: elif current_template != template_value:
# Template doesn't match, write value to template with retry and post-verification # Template doesn't match, write value to template with retry and post-verification
self.logger.info(f"{name}: Device name '{device_name}' matches key in config_other, but template doesn't match") self.logger.info(
f"{name}: Device name '{device_name}' matches key in config_other, but template doesn't match")
self.logger.info(f"{name}: Setting template to: {template_value}") self.logger.info(f"{name}: Setting template to: {template_value}")
import urllib.parse import urllib.parse
encoded_value = urllib.parse.quote(template_value) encoded_value = urllib.parse.quote(template_value)
@ -1189,9 +1191,13 @@ class TasmotaDiscovery:
continue continue
self.logger.info(f"{name}: Template command accepted") self.logger.info(f"{name}: Template command accepted")
# Add delay after Template command to allow device to process
time.sleep(0.5)
# Activate the template by setting module to 0 (Template module) # Activate the template by setting module to 0 (Template module)
module_url = f"http://{ip}/cm?cmnd=Module%200" module_url = f"http://{ip}/cm?cmnd=Module%200"
try: try:
self.logger.debug(f"{name}: Setting Module to 0 to activate template")
module_response = requests.get(module_url, timeout=10) module_response = requests.get(module_url, timeout=10)
if module_response.status_code != 200: if module_response.status_code != 200:
last_error = f"HTTP {module_response.status_code}" last_error = f"HTTP {module_response.status_code}"
@ -1200,6 +1206,9 @@ class TasmotaDiscovery:
time.sleep(1) time.sleep(1)
continue continue
self.logger.info(f"{name}: Module set to 0 successfully") self.logger.info(f"{name}: Module set to 0 successfully")
# Add delay after Module command to allow device to process
time.sleep(0.5)
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error setting module to 0: {last_error}") self.logger.warning(f"{name}: Error setting module to 0: {last_error}")
@ -1210,6 +1219,7 @@ class TasmotaDiscovery:
# Restart the device to apply the template # Restart the device to apply the template
restart_url = f"http://{ip}/cm?cmnd=Restart%201" restart_url = f"http://{ip}/cm?cmnd=Restart%201"
try: try:
self.logger.debug(f"{name}: Restarting device to apply template")
restart_response = requests.get(restart_url, timeout=10) restart_response = requests.get(restart_url, timeout=10)
if restart_response.status_code != 200: if restart_response.status_code != 200:
last_error = f"HTTP {restart_response.status_code}" last_error = f"HTTP {restart_response.status_code}"
@ -1219,17 +1229,20 @@ class TasmotaDiscovery:
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
# Restart may time out due to reboot; log and proceed to verification # Restart may time out due to reboot; log and proceed to verification
last_error = "Timeout" last_error = "Timeout"
self.logger.info(f"{name}: Restart timed out (device rebooting); proceeding to verification") self.logger.info(
f"{name}: Restart timed out (device rebooting); proceeding to verification")
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error restarting device: {last_error}") self.logger.warning(f"{name}: Error restarting device: {last_error}")
# Post-update verification: poll the device for the new template # Post-update verification: poll the device for the new template AND module
verified = False verified = False
for vtry in range(1, 4): for vtry in range(1, 4):
try: try:
# Wait a bit to let device come back # Wait a bit to let device come back
time.sleep(2 if vtry == 1 else 3) time.sleep(2 if vtry == 1 else 3)
# Verify template
vt_resp = requests.get(f"http://{ip}/cm?cmnd=Template", timeout=10) vt_resp = requests.get(f"http://{ip}/cm?cmnd=Template", timeout=10)
vt_data = vt_resp.json() vt_data = vt_resp.json()
# Extract template similarly to initial parse # Extract template similarly to initial parse
@ -1241,25 +1254,51 @@ class TasmotaDiscovery:
if isinstance(vt_data[first_key], str) and "{" in vt_data[first_key]: if isinstance(vt_data[first_key], str) and "{" in vt_data[first_key]:
new_template = vt_data[first_key] new_template = vt_data[first_key]
elif all(key in vt_data for key in ['NAME', 'GPIO', 'FLAG', 'BASE']): elif all(key in vt_data for key in ['NAME', 'GPIO', 'FLAG', 'BASE']):
import json
new_template = json.dumps(vt_data) new_template = json.dumps(vt_data)
if new_template == template_value:
self.logger.info(f"{name}: Template verification succeeded on attempt {vtry}") # Verify module is set to 0 (Template mode)
vm_resp = requests.get(f"http://{ip}/cm?cmnd=Module", timeout=10)
vm_data = vm_resp.json()
module_value = vm_data.get("Module", {})
# Module response can be {"Module":"0 (Generic)"} or similar
module_num = None
if isinstance(module_value, str):
# Extract number from "0 (Generic)" format
import re
match = re.match(r'^(\d+)', module_value)
if match:
module_num = match.group(1)
elif isinstance(module_value, (int, float)):
module_num = str(int(module_value))
if new_template == template_value and module_num == "0":
self.logger.info(
f"{name}: Template and Module verification succeeded on attempt {vtry}")
template_updated = True template_updated = True
verified = True verified = True
break break
elif new_template == template_value:
self.logger.warning(
f"{name}: Template verified but Module is {module_num}, not 0 (attempt {vtry})")
else:
self.logger.warning(
f"{name}: Template mismatch on verification (attempt {vtry})")
except Exception as ve: except Exception as ve:
self.logger.debug(f"{name}: Template verification attempt {vtry} failed: {ve}") self.logger.debug(f"{name}: Template verification attempt {vtry} failed: {ve}")
if verified: if verified:
break break
else: else:
last_error = last_error or "Verification failed" last_error = last_error or "Verification failed"
self.logger.warning(f"{name}: Template verification failed (attempt {attempt}/{max_attempts})") self.logger.warning(
f"{name}: Template verification failed (attempt {attempt}/{max_attempts})")
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
last_error = "Timeout" last_error = "Timeout"
self.logger.warning(f"{name}: Timeout updating template (attempt {attempt}/{max_attempts})") self.logger.warning(f"{name}: Timeout updating template (attempt {attempt}/{max_attempts})")
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error updating template: {last_error} (attempt {attempt}/{max_attempts})") self.logger.warning(
f"{name}: Error updating template: {last_error} (attempt {attempt}/{max_attempts})")
if attempt < max_attempts: if attempt < max_attempts:
time.sleep(1) time.sleep(1)
@ -1275,7 +1314,8 @@ class TasmotaDiscovery:
"error": last_error "error": last_error
}) })
else: else:
self.logger.debug(f"{name}: Device name '{device_name}' matches key in config_other and template matches value") self.logger.debug(
f"{name}: Device name '{device_name}' matches key in config_other and template matches value")
else: else:
# No key matches device name, check if any value matches the template # No key matches device name, check if any value matches the template
matching_key = None matching_key = None
@ -1283,12 +1323,12 @@ class TasmotaDiscovery:
if value == current_template: if value == current_template:
matching_key = key matching_key = key
break break
if matching_key: if matching_key:
# Value matches template, write key to device name # Value matches template, write key to device name
self.logger.info(f"{name}: Template matches value for key '{matching_key}' in config_other") self.logger.info(f"{name}: Template matches value for key '{matching_key}' in config_other")
self.logger.info(f"{name}: Setting device name to: {matching_key}") self.logger.info(f"{name}: Setting device name to: {matching_key}")
max_attempts = 3 max_attempts = 3
last_error = None last_error = None
for attempt in range(1, max_attempts + 1): for attempt in range(1, max_attempts + 1):
@ -1304,9 +1344,13 @@ class TasmotaDiscovery:
continue continue
self.logger.info(f"{name}: Device name command accepted") self.logger.info(f"{name}: Device name command accepted")
# Add delay after DeviceName command to allow device to process
time.sleep(0.5)
# Activate the template by setting module to 0 (Template module) # Activate the template by setting module to 0 (Template module)
module_url = f"http://{ip}/cm?cmnd=Module%200" module_url = f"http://{ip}/cm?cmnd=Module%200"
try: try:
self.logger.debug(f"{name}: Setting Module to 0 to activate template")
module_response = requests.get(module_url, timeout=10) module_response = requests.get(module_url, timeout=10)
if module_response.status_code != 200: if module_response.status_code != 200:
last_error = f"HTTP {module_response.status_code}" last_error = f"HTTP {module_response.status_code}"
@ -1315,6 +1359,9 @@ class TasmotaDiscovery:
time.sleep(1) time.sleep(1)
continue continue
self.logger.info(f"{name}: Module set to 0 successfully") self.logger.info(f"{name}: Module set to 0 successfully")
# Add delay after Module command to allow device to process
time.sleep(0.5)
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error setting module to 0: {last_error}") self.logger.warning(f"{name}: Error setting module to 0: {last_error}")
@ -1325,6 +1372,7 @@ class TasmotaDiscovery:
# Restart the device to apply the template # Restart the device to apply the template
restart_url = f"http://{ip}/cm?cmnd=Restart%201" restart_url = f"http://{ip}/cm?cmnd=Restart%201"
try: try:
self.logger.debug(f"{name}: Restarting device to apply template")
restart_response = requests.get(restart_url, timeout=10) restart_response = requests.get(restart_url, timeout=10)
if restart_response.status_code != 200: if restart_response.status_code != 200:
last_error = f"HTTP {restart_response.status_code}" last_error = f"HTTP {restart_response.status_code}"
@ -1333,37 +1381,64 @@ class TasmotaDiscovery:
self.logger.info(f"{name}: Device restart initiated successfully") self.logger.info(f"{name}: Device restart initiated successfully")
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
last_error = "Timeout" last_error = "Timeout"
self.logger.info(f"{name}: Restart timed out (device rebooting); proceeding to verification") self.logger.info(
f"{name}: Restart timed out (device rebooting); proceeding to verification")
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error restarting device: {last_error}") self.logger.warning(f"{name}: Error restarting device: {last_error}")
# Post-update verification: poll Status 0 for the new device name # Post-update verification: poll Status 0 for the new device name AND module
verified = False verified = False
for vtry in range(1, 4): for vtry in range(1, 4):
try: try:
time.sleep(2 if vtry == 1 else 3) time.sleep(2 if vtry == 1 else 3)
# Verify device name
v_resp = requests.get(f"http://{ip}/cm?cmnd=Status%200", timeout=10) v_resp = requests.get(f"http://{ip}/cm?cmnd=Status%200", timeout=10)
v_data = v_resp.json() v_data = v_resp.json()
new_name = v_data.get("Status", {}).get("DeviceName", "") new_name = v_data.get("Status", {}).get("DeviceName", "")
if new_name == matching_key:
self.logger.info(f"{name}: Device name verification succeeded on attempt {vtry}") # Verify module is set to 0 (Template mode)
vm_resp = requests.get(f"http://{ip}/cm?cmnd=Module", timeout=10)
vm_data = vm_resp.json()
module_value = vm_data.get("Module", {})
module_num = None
if isinstance(module_value, str):
import re
match = re.match(r'^(\d+)', module_value)
if match:
module_num = match.group(1)
elif isinstance(module_value, (int, float)):
module_num = str(int(module_value))
if new_name == matching_key and module_num == "0":
self.logger.info(
f"{name}: Device name and Module verification succeeded on attempt {vtry}")
template_updated = True template_updated = True
verified = True verified = True
break break
elif new_name == matching_key:
self.logger.warning(
f"{name}: Device name verified but Module is {module_num}, not 0 (attempt {vtry})")
else:
self.logger.warning(
f"{name}: Device name mismatch on verification (attempt {vtry})")
except Exception as ve: except Exception as ve:
self.logger.debug(f"{name}: Device name verification attempt {vtry} failed: {ve}") self.logger.debug(f"{name}: Device name verification attempt {vtry} failed: {ve}")
if verified: if verified:
break break
else: else:
last_error = last_error or "Verification failed" last_error = last_error or "Verification failed"
self.logger.warning(f"{name}: Device name verification failed (attempt {attempt}/{max_attempts})") self.logger.warning(
f"{name}: Device name verification failed (attempt {attempt}/{max_attempts})")
except requests.exceptions.Timeout: except requests.exceptions.Timeout:
last_error = "Timeout" last_error = "Timeout"
self.logger.warning(f"{name}: Timeout updating device name (attempt {attempt}/{max_attempts})") self.logger.warning(
f"{name}: Timeout updating device name (attempt {attempt}/{max_attempts})")
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
last_error = str(e) last_error = str(e)
self.logger.warning(f"{name}: Error updating device name: {last_error} (attempt {attempt}/{max_attempts})") self.logger.warning(
f"{name}: Error updating device name: {last_error} (attempt {attempt}/{max_attempts})")
if attempt < max_attempts: if attempt < max_attempts:
time.sleep(1) time.sleep(1)
@ -1386,14 +1461,15 @@ class TasmotaDiscovery:
print(f"\nNo template match found for device {name} at {ip}") print(f"\nNo template match found for device {name} at {ip}")
print(f" Device Name on device: '{device_name}'") print(f" Device Name on device: '{device_name}'")
print(f" Template on device: '{current_template}'") print(f" Template on device: '{current_template}'")
print("Please add an appropriate entry to device_list (preferred) or legacy config_other in your configuration file.") print(
"Please add an appropriate entry to device_list (preferred) or legacy config_other in your configuration file.")
return template_updated return template_updated
except requests.exceptions.RequestException as e: except requests.exceptions.RequestException as e:
self.logger.error(f"Error checking/updating template for device at {ip}: {str(e)}") self.logger.error(f"Error checking/updating template for device at {ip}: {str(e)}")
return False return False
def configure_mqtt_settings(self, ip, name, mqtt_status=None, is_new_device=False, set_friendly_name=False, enable_mqtt=False, with_retry=False, reboot=False): def configure_mqtt_settings(self, ip, name, mqtt_status=None, is_new_device=False, set_friendly_name=False, enable_mqtt=False, with_retry=False, reboot=False):
"""Configure MQTT settings for a device. """Configure MQTT settings for a device.