ksheumaker / homeassistant-apsystems_ecur

Home Assistant custom component for local querying of APSystems ECU-R Solar System
Apache License 2.0
166 stars 42 forks source link

Incorrect today energy resulting in double amount #245

Open marcusds opened 3 months ago

marcusds commented 3 months ago

Firmware: ECU_R_PRO_2.1.17 Replicated on 1.3.1 and 1.4.1

This happens pretty regularly, every 2nd day or so I would say.

From the logs the issue seems to be that there is a query that returns today_energy as the correct amount, then one that returns zero, and then the next that returns the correct value again.

My guess is that since the state class is total_increasing having it go back down to zero and then back up is causing issues? Does it maybe make sense to just add a filter that on the same day if today_energy suddenly returns 0 just ignore that query?

I am attaching the full logs, but adding some excerpts to help make it easier.

home-assistant_apsystems_ecur_2024-03-26T08-08-13.633Z.log

Correct response:

2024-03-25 18:21:46.264 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur] Querying ECU...
2024-03-25 18:21:51.266 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur.APSystemsSocket] b'41505331323031313130303031323136323030303333353130303100039b6e0000016200001423202403251820230006000631303031364543555f525f50524f5f322e312e313730313055532f5061636966696380971b033ecb60c5a87a833a303000000000000000000000454e440a'
2024-03-25 18:22:01.269 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130313637303030323030303100062024032518162380400007056401303302580074000f00eb000e000e000c80400007079101303302570073000f00eb000f000f000f80400007049101303302580072001000eb000f000e000f80400007010301303302570071000f00eb000f000e000f80400007001101303302570073000f00ea000f0010000f80400007135301303302570071000f00eb000e000f000f454e440a'
2024-03-25 18:22:01.270 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130303630303033303030804000070564d6804000070791d9804000070491e2804000070103d6804000070011d6804000071353d0454e440a'
2024-03-25 18:22:01.270 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur] Got data from ECU
2024-03-25 18:22:01.270 DEBUG (SyncWorker_8) [custom_components.apsystems_ecur] Returning {'timestamp': '2024-03-25 18:16:23', 'inverters': {'804000070564': {'uid': '804000070564', 'online': True, 'signal': 83, 'temperature': 16, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [15, 14, 14, 12], 'voltage': [235]}, '804000070791': {'uid': '804000070791', 'online': True, 'signal': 85, 'temperature': 15, 'frequency': 59.9, 'model': 'QS1', 'channel_qty': 4, 'power': [15, 15, 15, 15], 'voltage': [235]}, '804000070491': {'uid': '804000070491', 'online': True, 'signal': 88, 'temperature': 14, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [16, 15, 14, 15], 'voltage': [235]}, '804000070103': {'uid': '804000070103', 'online': True, 'signal': 83, 'temperature': 13, 'frequency': 59.9, 'model': 'QS1', 'channel_qty': 4, 'power': [15, 15, 14, 15], 'voltage': [235]}, '804000070011': {'uid': '804000070011', 'online': True, 'signal': 83, 'temperature': 15, 'frequency': 59.9, 'model': 'QS1', 'channel_qty': 4, 'power': [15, 15, 16, 15], 'voltage': [234]}, '804000071353': {'uid': '804000071353', 'online': True, 'signal': 81, 'temperature': 13, 'frequency': 59.9, 'model': 'QS1', 'channel_qty': 4, 'power': [15, 14, 15, 15], 'voltage': [235]}}, 'today_energy': 51.55, 'ecu_id': '216200033510', 'lifetime_energy': 23639.8, 'current_power': 354, 'qty_of_inverters': 6, 'qty_of_online_inverters': 6, 'data_from_cache': False, 'querying': True, 'restart_ecu': False}
2024-03-25 18:22:01.271 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.008 seconds (success: True)

Next query returning today_energy = 0

2024-03-25 18:27:01.265 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur] Querying ECU...
2024-03-25 18:27:06.267 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur.APSystemsSocket] b'41505331323031313130303031323136323030303333353130303100039b6e000000f100000000202403251825240000000631303031364543555f525f50524f5f322e312e313730313055532f5061636966696380971b033ecb60c5a87a833a303000000000000000000000454e440a'
2024-03-25 18:27:16.270 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130313637303030323030303100062024032518262380400007056401303302570073000b00ec000a0009000980400007079101303302580073000a00ec0009000a000a80400007049101303302580072000b00ec000a000a000b80400007010301303302580071000b00eb000a0009000980400007001101303302580072000b00ec000a000a000a80400007135301303302580071000b00ec000a000a000a454e440a'
2024-03-25 18:27:16.270 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130303630303033303030804000070564d1804000070791d9804000070491e4804000070103d5804000070011d5804000071353d1454e440a'
2024-03-25 18:27:16.271 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur] Got data from ECU
2024-03-25 18:27:16.271 DEBUG (SyncWorker_49) [custom_components.apsystems_ecur] Returning {'timestamp': '2024-03-25 18:26:23', 'inverters': {'804000070564': {'uid': '804000070564', 'online': True, 'signal': 0, 'temperature': 15, 'frequency': 59.9, 'model': 'QS1', 'channel_qty': 4, 'power': [11, 10, 9, 9], 'voltage': [236]}, '804000070791': {'uid': '804000070791', 'online': True, 'signal': 0, 'temperature': 15, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [10, 9, 10, 10], 'voltage': [236]}, '804000070491': {'uid': '804000070491', 'online': True, 'signal': 0, 'temperature': 14, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [11, 10, 10, 11], 'voltage': [236]}, '804000070103': {'uid': '804000070103', 'online': True, 'signal': 0, 'temperature': 13, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [11, 10, 9, 9], 'voltage': [235]}, '804000070011': {'uid': '804000070011', 'online': True, 'signal': 0, 'temperature': 14, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [11, 10, 10, 10], 'voltage': [236]}, '804000071353': {'uid': '804000071353', 'online': True, 'signal': 0, 'temperature': 13, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [11, 10, 10, 10], 'voltage': [236]}}, 'today_energy': 0.0, 'ecu_id': '216200033510', 'lifetime_energy': 23639.8, 'current_power': 241, 'qty_of_inverters': 0, 'qty_of_online_inverters': 6, 'data_from_cache': False, 'querying': True, 'restart_ecu': False}
2024-03-25 18:27:16.273 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.008 seconds (success: True)

Next response again correct:

2024-03-25 18:32:16.264 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur] Querying ECU...
2024-03-25 18:32:21.266 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur.APSystemsSocket] b'41505331323031313130303031323136323030303333353130303100039b6f000000aa00001429202403251830260006000631303031364543555f525f50524f5f322e312e313730313055532f5061636966696380971b033ecb60c5a87a833a303000000000000000000000454e440a'
2024-03-25 18:32:31.269 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130313637303030323030303100062024032518312380400007056401303302580073000600ed00060005000580400007079101303302580073000700ec00060007000680400007049101303302580072000900ec00070007000780400007010301303302580071000900eb00080008000880400007001101303302580072000900eb00080008000880400007135301303302580070000700ec000600060007454e440a'
2024-03-25 18:32:31.270 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur.APSystemsSocket] b'415053313130303630303033303030804000070564d5804000070791db804000070491e4804000070103d3804000070011d5804000071353d1454e440a'
2024-03-25 18:32:31.270 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur] Got data from ECU
2024-03-25 18:32:31.270 DEBUG (SyncWorker_57) [custom_components.apsystems_ecur] Returning {'timestamp': '2024-03-25 18:31:23', 'inverters': {'804000070564': {'uid': '804000070564', 'online': True, 'signal': 83, 'temperature': 15, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [6, 6, 5, 5], 'voltage': [237]}, '804000070791': {'uid': '804000070791', 'online': True, 'signal': 85, 'temperature': 15, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [7, 6, 7, 6], 'voltage': [236]}, '804000070491': {'uid': '804000070491', 'online': True, 'signal': 89, 'temperature': 14, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [9, 7, 7, 7], 'voltage': [236]}, '804000070103': {'uid': '804000070103', 'online': True, 'signal': 82, 'temperature': 13, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [9, 8, 8, 8], 'voltage': [235]}, '804000070011': {'uid': '804000070011', 'online': True, 'signal': 83, 'temperature': 14, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [9, 8, 8, 8], 'voltage': [235]}, '804000071353': {'uid': '804000071353', 'online': True, 'signal': 81, 'temperature': 12, 'frequency': 60.0, 'model': 'QS1', 'channel_qty': 4, 'power': [7, 6, 6, 7], 'voltage': [236]}}, 'today_energy': 51.61, 'ecu_id': '216200033510', 'lifetime_energy': 23639.9, 'current_power': 170, 'qty_of_inverters': 6, 'qty_of_online_inverters': 6, 'data_from_cache': False, 'querying': True, 'restart_ecu': False}
2024-03-25 18:32:31.271 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.007 seconds (success: True)

Including some screenshots to help visualize what I mean: image image image

marcusds commented 3 months ago

This seems to be a similar issue to #126, but just for today_energy

marcusds commented 3 months ago

I created a PR #246, but I think there has to be a better solution.

HAEdwin commented 3 months ago

It makes total sense to implement a filter indeed, thank you for this.

I'd suggest a check in apsystemssocket.py around line 121; when self.qty_of_online_inverters > 0 and self today_energy != 0 then data["today_energy"] = self.today_energy

Is that an idea?

Btw, I'm running a proxy also and found out the ECU indeed seems to sometimes create these weird values that need filtering.

marcusds commented 3 months ago

I'd suggest a check in apsystemssocket.py around line 121; when self.qty_of_online_inverters > 0 and self today_energy != 0 then data["today_energy"] = self.today_energy

That was my first thought as well but I am not familiar enough with the logic of what turns on the inverters on/off. I was worried there could be scenarios where the inverters are off then back on again during the productive period of a day. But I realize now as I am typing this that won't be an issue since we aren't setting a value for today_energy at all.

I'll raise a new PR soon.

HAEdwin commented 3 months ago

That's right, I haven't considered the code change in detail yet - busy with regular work. Taking all scenarios into account, we should be fine with this solution (including the reset of the today_energy initiated by the ECU). Your contribution is highly appreciated Thnx!

marcusds commented 3 months ago

I just realized in my logs when 'today_energy': 0, then 'qty_of_inverters': 0 and 'qty_of_online_inverters': 6 which seems like an odd scenario and perhaps the best way to filter is just off that. I can't picture a scenario where my inverters disappear and I need to log my energy output.

I updated my #246 to have the logic based off that a bad reporting of today_energy will include a bad reporting of qty_of_inverters. If that isn't always the case we can look at another solution, but for now this looks like the best option.

I considered leaving in the tracking cache date and resetting cached today_energy to 0. But that could be its own can of worms and would best be its own PR, if at all, rather than part of this fix.

marcusds commented 1 month ago

I've recently gotten 2 days of odd results that seem similar to this issue. Didn't have logging on so have no more details. Will try to get some.

HAEdwin commented 1 month ago

Did you try the beta version allready?

marcusds commented 1 month ago

Yeah I'm on the beta

JasNeto10 commented 1 month ago

Hello, how do I install the beta version? I'm using 1.4.1 and I'm having this same problem.

HAEdwin commented 1 month ago

Hacs > select overflow menu right from the repository > select redownload > enable the switch Show beta versions

JasNeto10 commented 1 month ago

I downloaded the beta version, but the integration still shows version 1.4.1.... is that really the case?

JasNeto10 commented 1 month ago

IMG_1862

JasNeto10 commented 1 month ago

Yesterday it looked like this and I had already downloaded the beta version a few days ago. IMG_1861