serkri / SmartEVSE-3

Smart Electric Vehicle Charging Station (EVSE)
MIT License
67 stars 28 forks source link

MQTT: SmartEVSE publishing to strange topics and incorrect data #192

Closed kuhlivisj closed 11 months ago

kuhlivisj commented 11 months ago

I'm seeing some strange topics when monitoring MQTT. Also sometimes correct topics get strange values. In the screenshot the lasst 4 topics are wrong and MainsCurrentL1 has a strange value.

image

My SmartEVSE is running v1.7.2.

dingo35 commented 11 months ago

If you watch the same data on the webserver, "Raw Data", same problem or values ok there?

kuhlivisj commented 11 months ago

On the "Raw Data" page the values seem correct.

On the "Raw Data" page it says that MQTT is disconnected yet it is publishing to the broker.

dingo35 commented 11 months ago

Does reconfiguring your MQTT settings on the webserver page change anything?

I cannot reproduce this at my site.

kuhlivisj commented 11 months ago

I tried it. Changed the settings to some random value and saved them. The SmartEVSE indicated that it was disconnected. Then I changed the settings back to the correct values and saved them. The SmartEVSE connected again and after a few minutes I see the same problem again.

It looks like it has something to do with writing the mainsmeter data to the SmartEVSE over MQTT. When I don't send it everything is working as expected. When I start sending the data again the problem is back.

dingo35 commented 11 months ago

Does v1.7.1 have the same problem?

kuhlivisj commented 11 months ago

Tried v1.7.1 for 15 minutes now and it is working fine.

dingo35 commented 11 months ago

Are you willing and able to compile yourself?

dingo35 commented 11 months ago

It is not very complicated, and this way you can find out which commit causes the problem; first do git checkout (some commit in the middle of v1.7.1 and v1.7.2) --> test if problem exists work your way down to 1.7.1 else work your way up to 1.7.2 .

Building the firmware

kuhlivisj commented 11 months ago

Commit 61f49cf1624630d816774078d07164c65477daff is causing the problems.

Tried a few different commits, but the problems start with that commit.

dingo35 commented 11 months ago

Interesting, that code updates publishes the currents immediately after they change; Im going to review that code tomorrow....

hmmbob commented 11 months ago

It might not just be the currents though, my HA complains about some random data in other fields as well

Screenshot_20230806_164904_Home Assistant

2023-08-06 16:49:08.920 ERROR (MainThread) [homeassistant.components.mqtt.select] Invalid option for select.smartevse_11469_modeselector: 'sCurr' (valid options: ['Off', 'Normal', 'Smart', 'Solar'])
2023-08-06 16:49:08.922 ERROR (MainThread) [homeassistant.components.mqtt.select] Invalid option for select.smartevse_11469_mode: 'sCurr' (valid options: ['Off', 'Normal', 'Smart', 'Solar'])
2023-08-06 16:50:41.899 ERROR (MainThread) [homeassistant.util.logging] Exception in message_received when handling msg on 'SmartEVSE-11469/MainsCurrentL2': '0#'
Traceback (most recent call last):
File "/usr/src/homeassistant/homeassistant/components/mqtt/debug_info.py", line 44, in wrapper
msg_callback(msg)
File "/usr/src/homeassistant/homeassistant/components/mqtt/sensor.py", line 293, in message_received
_update_state(msg)
File "/usr/src/homeassistant/homeassistant/components/mqtt/sensor.py", line 244, in _update_state
payload = self._template(msg.payload, PayloadSentinel.DEFAULT)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/components/mqtt/models.py", line 251, in async_render_with_possible_json_value
rendered_payload = self._value_template.async_render_with_possible_json_value(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/template.py", line 735, in async_render_with_possible_json_value
return _render_with_context(self.template, compiled, **variables).strip()
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/src/homeassistant/homeassistant/helpers/template.py", line 2179, in _render_with_context
return template.render(**kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/jinja2/environment.py", line 1301, in render
self.environment.handle_exception()
File "/usr/local/lib/python3.11/site-packages/jinja2/environment.py", line 936, in handle_exception
raise rewrite_traceback_stack(source=source)
File "<template>", line 1, in top-level template code
File "/usr/src/homeassistant/homeassistant/helpers/template.py", line 1927, in forgiving_int_filter
raise_no_default("int", value)
File "/usr/src/homeassistant/homeassistant/helpers/template.py", line 1609, in raise_no_default
raise ValueError(
ValueError: Template error: int got invalid input '0#' when rendering template '{{ value | int / 10 }}' but no default was specified
dingo35 commented 11 months ago

@hmmbob Your problems also arise when you are feeding Mains Currents L1 - L3 via MQTT? Also problems disappear when stop feeding? Also problems disappear when using v1.7.1?

hmmbob commented 11 months ago

I am not feeding L1-L3 through MQTT, but through API (http post). Rollback to 1.7.1 fixes the issue.

edit: first thought; are we running out of storage/memory somewhere? edit2: I see some new parameter to store was added, could this trigger this behaviour?

https://github.com/serkri/SmartEVSE-3/blob/8a0c57edd7991cb9eb735d24b05bbd1ed5eeb135/SmartEVSE-3/src/evse.cpp#L2342-L2347

dingo35 commented 11 months ago

Im not, since I dont get to reproduce this problem.

If you want to check free ram, uncomment lines in src/evse.cpp that contain the string "free ram", and check debug log via telnet.

If necessary you can increase stack sizes of different tasks, src/evse.cpp look for comment "Stack size".

marcovaneck commented 11 months ago

Rarely I see this problem. My 2 cents are in the multi-threading area. Since in 1.7.2 the Currents are updated in the void UpdateCurrentData(void) method, which is called from several places. As a proof of concept I moved them back to the mqttPublishData() method. Let you know if the problem disappears.

Ps. I push the current-data via the web-interface, not via MQTT.

dingo35 commented 11 months ago

I agree that is much more probable; and Im convinced the problem is solved by placing the publish statements back to the publishdata function.

But I dont see that as a solution, since the long term goal is to feed the mqtt server immediately (and only) if values change.

So the solution would be to make the publish routine threadsafe; to do that effectively it is necessary to find out what part of the library is the problem OR move to a threadsafe mqtt library.

dingo35 commented 11 months ago

mutex.zip As a proof of concept I placed mutex locks around the publish calls; could someone who can reproduce the problem test this?

EDIT: Another approach would be not to publish currents from a meter (Mains, EV or PV) if they are of type EM_API. It doesnt really make sense to republish data that is just received, does it? Or am I missing a use case here?

kuhlivisj commented 11 months ago

The version with the mutex is working fine. No more corrupted data and topics.

dingo35 commented 11 months ago

Fixed with 2020c53edcfb