Bypass state not recognized correctly on Hub2000

floriandrott commented 5 months ago

If the battery is completely full (100%) the hub goes into bybass mode. The bypass mode is not correctly detected by solarflow.

Home Assistant integration shows

Based on the MQTT topics it should detect the bypass state:

The MQTT value goes to "2" which means bypass on but as shown in picture one, the solarflow-control is not detecting it.

reinhard-brandstaedter commented 5 months ago

Are you just noticing that the HA sensor is not properly reporting, or is the hub actually not in bypass state? Did you check directly in MQTT what the reported state is?

It should show it like this:

floriandrott commented 5 months ago

In the morning I switched over to the DEV build. Today the batterie reached again 100% and the hub went into bypass mode. In MQTT Explorer I see

The hub went into bypass but solarflow-control is not really seeing it. The log is saying HUB: S:200.5W [ 200.5,200.5 ], B:100% (100), V:51.5V (51.5), C: 0W, P:False (manual, not possible), F:0.0h, E:-1.0h, H: 0W, L:600W Based on time, solarpower (200.5W) minimum charge power (175W) and bypass state (False), hub could contribute 300.8W - Decision path: 2.1.

reinhard-brandstaedter commented 5 months ago

pass=0 means the hub is NOT in bypass (yet). passMode=2 means it SHOULD switch to bypass on, however it can take a bit until the hub actually switches ( needs to reduce solarinput first )

floriandrott commented 5 months ago

Ah, okay. Right now I have 360W as solarinput but still pass=0 and passMode=2. Is this normal that it takes so long?

floriandrott commented 5 months ago

I double checked the values, solarinput went to 0 W but still pass=0 and passMode=2. There was also no energy feed from the battery to the house. I manually turned off "bypass" in HA by the control elements. Now the hub is contributing energy to the house via the battery.

I'm happy to contribute in any way with log files, etc. Just let me know :)

reinhard-brandstaedter commented 5 months ago

Actually the HA switch for passMode is not correct (@ricariel ?). passMode = 2 is manual on passMode = 1 is manual off passMode = 0 is auto (let hub firmware decide) So if you switch it to "off" in HA, you are actually switching the hub to "auto" mode, where we have seen all kinds of delays when the firmware will decide to turn it on ...

If you check the solarflow-control logs you will see various infos about the bypass: P:False (manual, not possible) : means BP is reported off but in manual mode (passMode=1), sf-controls own logic has set any change to not possible meaning it will currently not turn it on (avoiding frequent switches like in the firmware) P:False (manual, possible) : means it is off but sf-control will turn it on once the battery reaches 100% P:True (manual, possible): means it is on and sf-control is controlling it P:True|False (auto, ...): means passMode = 0 , the hubs firmware controls it

In your logs you should observe the state of this, usually the hub is switched to (manual, possible) in the morning at sunrise (if control_bypass = true is set in your config). Once the bypass is on, sf-control will turn it off and sunset - offset if demand is higher than what is delivered via bypass (so it can start discharging if needed).

At sunrise you should see something like this (note that the bypass OFF is enforcing as sometimes the hub - if shut down - seems to reset the passMode to auto) :

05:40:18,185:INFO: HUB: S:0.0W [ 0.0 ], B: 19% (20|19|19), V:48.4V (48.4|48.5|48.4), C:-164W, P:False (manual, possible), F:10.0h, E:70.4h, H:157W, L:700W
05:40:18,187:INFO: INV: AC:154.7W, AC_Prediction: 154.8W, DC:162.7W, DC_prediction: 162.8W (2.2|1.5|158.3|0.0), L:596W (149.0W/channel) [2000W]
05:40:18,188:INFO: SMT: T:Smartmeter P:10.0W [ 8.8,8.8,8.8,8.7,9.8,10.4 ] Predict: 7.9W
05:40:18,188:INFO: Direct connected panel are producing 0.0W, trying to get 150.9W from hub.
05:40:18,188:INFO: Good morning! We have consumed 72% of the battery tonight!
05:40:18,188:INFO: Turning hub bypass OFF

Once the hub gets close to 100% battery it will reduce charging power (and thus solar input) to almost zero. At 100% battery level sf-control will then switch the bypass on. At this time likely your inverter is offline if you have no direct connected panels:

13:47:53,767:INFO: Bypass control, turning on bypass!
13:47:53,767:INFO: Turning hub bypass ON
13:47:53,808:INFO: Reading last full time: 2024-05-13 13:47:53
13:47:53,809:INFO: Reading battery target mode: discharging
13:48:07,119:INFO: HUB: S:26.7W [ 35.9,35.9,26.7 ], B:100% (100|100|100), V:53.7V (53.6|53.7|53.7), C: 0W, P:True (manual, not possible), F:0.0h, E:78.5h, H: 9W, L: 0W
13:48:07,121:INFO: INV: AC:673.6W, AC_Prediction: 673.6W, DC:709.0W, DC_prediction: 709.2W (329.8|379.2|0.0|0.0), L:1460W (365.0W/channel) [2000W]
13:48:07,122:INFO: SMT: T:Smartmeter P:-666.0W [ -314.0,-314.0,-316.2,-320.2,-325.2,-337.4 ] Predict: -287.3W

Or in color:

floriandrott commented 5 months ago

Thanks for all the details. I checked the logs today and following happened with the current dev-release (pulled this morning).

2024-05-14 17:32:57,705:INFO: HUB: S:598.7W [ 640.9,640.9,632.8,598.7 ], B: 99% (99), V:53.5V (53.5), C: 233W, P:False (manual, possible), F:20.5h, E:-1.0h, H:286W, L:600W
2024-05-14 17:32:57,707:INFO: INV: AC:284.6W, AC_Prediction: 284.6W, DC:300.4W, DC_prediction: 290.2W (150.7|150.8), L:278W (138.8W/channel) [800W]
2024-05-14 17:32:57,710:INFO: SMT: T:Smartmeter P:24.0W [ 64.5,64.5,59.9,44.0,26.5,28.4 ] Predict: 82.0W
2024-05-14 17:32:57,710:INFO: Based on time, solarpower (598.7W) minimum charge power (10W) and bypass state (False), hub could contribute 299.0W - Decision path: 1.1.

Then the batterie reached 100%

2024-05-14 17:32:58,769:INFO: Bypass control, turning on bypass!
2024-05-14 17:32:58,770:INFO: Turning hub bypass ON
2024-05-14 17:32:58,770:INFO: HUB triggers limit function: 628.7 -> 589.9: skipped
2024-05-14 17:32:58,771:INFO: Reading last full time: 2024-05-14 17:32:58
2024-05-14 17:32:58,811:INFO: Reading battery target mode: discharging

Interesting is that BP is still recognized as FALSE as seen in the logs directly afterwards:

2024-05-14 17:33:12,954:INFO: HUB: S:411.1W [ 545.5,545.5,540.6,530.1,470.7,411.1 ], B:100% (100), V:53.5V (53.5), C: 95W, P:False (manual, not possible), F:0.0h, E:-1.0h, H: 70W, L:600W
2024-05-14 17:33:12,957:INFO: INV: AC:192.0W, AC_Prediction: 235.3W, DC:203.0W, DC_prediction: 248.6W (0.3|0.8), L:298W (148.8W/channel) [800W]
2024-05-14 17:33:12,958:INFO: SMT: T:Smartmeter P:310.0W [ 88.5,88.5,108.6,118.8,144.6,163.7 ] Predict: 65.0W
2024-05-14 17:33:12,959:INFO: Direct connected panel are producing 0.0W, trying to get 148.7W from hub.
2024-05-14 17:33:12,959:INFO: Based on time, solarpower (411.1W) minimum charge power (10W) and bypass state (False), hub could contribute 148.7W - Decision path: 1.1.
2024-05-14 17:33:12,959:INFO: Not setting solarflow output limit to 600.0W as it is identical to current limit!
2024-05-14 17:33:12,959:INFO: Solarflow is willing to contribute 74.0W (per channel) of the requested 148.7!
2024-05-14 17:33:12,959:INFO: Setting inverter output limit to 148W (1 min moving average of 74W x 2)

In your screenshot BP is TRUE, but somehow this isn't the case on my side. control_bypass = true is set in the config file. Any ideas why this happens?

ricariel commented 5 months ago

I use this switch for Bypass and it works:

select: name: "Bypass Modus" unique_id: "serial-passMode" state_topic: "solarflow-hub/serial/telemetry/passMode" value_template: "{{ 'Auto' if value=='0' else ('Off' if value=='1' else ('On' if value=='2' else 'Unknown')) }}"
options:
- 'Auto'
- 'Off'
- 'On' command_topic: "iot/73bkTV/serial/properties/write" command_template: "{\"properties\": {\"passMode\": {{ '0' if value=='Auto' else ('1' if value=='Off' else ('2' if value=='On' else '0')) }} }}"
  device: name: "SolarFlow Hub 1200" identifiers: "serial" manufacturer: "Zendure" model: "SmartPV Hub 1200 Controller"

reinhard-brandstaedter commented 5 months ago

ahja, that is a better and correct solution than what is currently pushed as template.

mavo commented 5 months ago

Nonsense used to be here... Removed... Same for next comment, which I removed entirely.

mavo commented 5 months ago

Hello @reinhard-brandstaedter, sorry to bother you again.

In an effort to understand whats happening, I scrolled through the logs of the day and actually noticed, the app apparently never really understand the hubs BP mode for me. Here is the log of the time when it turned on, but the app never realized.

2024-05-16 11:31:12,685:INFO: HUB: S:745.5W [ 969.4,969.4,918.0,867.9,810.0,745.5 ], B: 99% (100|99), V:53.1V (53.3|53.0), C: 444W, P:False (manual, possible), F:17.9h, E:198.6h, H:224W, L:800W
2024-05-16 11:31:12,685:INFO: INV: AC:223.7W, AC_Prediction: 223.7W, DC:235.4W, DC_prediction: 235.4W (0.0|0.0|119.2|115.7), L:448W (112.0W/channel) [1600W]
2024-05-16 11:31:12,687:INFO: SMT: T:ShellyEM3 P:9.7W [ 12.2,12.2,10.1,8.9,10.1,13.4 ] Predict: 15.3W
2024-05-16 11:31:12,687:INFO: Direct connected panel are producing 0.0W, trying to get 226.7W from hub.
2024-05-16 11:31:12,687:INFO: Based on time, solarpower (745.5W) minimum charge power (0W) and bypass state (False), hub could contribute 226.7W - Decision path: 1.1.
2024-05-16 11:31:12,687:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:31:12,688:INFO: Solarflow is willing to contribute 113.0W (per channel) of the requested 226.7!
2024-05-16 11:31:12,688:INFO: Not setting inverter output limit as it is identical to current limit!
2024-05-16 11:31:12,688:INFO: Sun: 05:09 - 20:59 Demand: 226.7W, Panel DC: (0.0W), Hub DC: (223.3W), Inverter Limit: 452.0W, Hub Limit: 800.0W
2024-05-16 11:31:12,688:INFO: HUB triggers limit function: 810.0 -> 745.5: executed
2024-05-16 11:31:13,726:INFO: HUB triggers limit function: 798.8 -> 733.4: skipped
2024-05-16 11:31:14,733:INFO: HUB triggers limit function: 787.8 -> 721.6: skipped
2024-05-16 11:31:15,743:INFO: HUB triggers limit function: 776.8 -> 717.5: skipped
2024-05-16 11:31:16,772:INFO: HUB triggers limit function: 766.0 -> 713.5: skipped
2024-05-16 11:31:17,786:INFO: HUB triggers limit function: 755.2 -> 709.5: skipped
2024-05-16 11:31:18,809:INFO: HUB triggers limit function: 744.5 -> 700.0: skipped
2024-05-16 11:31:19,834:INFO: HUB triggers limit function: 733.9 -> 696.2: skipped
2024-05-16 11:31:20,852:INFO: HUB triggers limit function: 723.5 -> 692.5: skipped
2024-05-16 11:31:31,049:INFO: HUB: S:625.5W [ 781.6,781.6,733.2,685.1,658.2,625.5 ], B: 99% (100|99), V:53.1V (53.3|53.0), C: 334W, P:False (manual, possible), F:17.9h, E:198.6h, H:220W, L:800W
2024-05-16 11:31:31,049:INFO: INV: AC:223.4W, AC_Prediction: 223.4W, DC:235.2W, DC_prediction: 235.2W (0.0|0.0|119.9|116.3), L:448W (112.0W/channel) [1600W]
2024-05-16 11:31:31,051:INFO: SMT: T:ShellyEM3 P:8.9W [ 10.6,10.6,11.6,13.6,13.6,13.8 ] Predict: 5.5W
2024-05-16 11:31:31,052:INFO: Direct connected panel are producing 0.0W, trying to get 228.2W from hub.
2024-05-16 11:31:31,052:INFO: Based on time, solarpower (625.5W) minimum charge power (0W) and bypass state (False), hub could contribute 228.2W - Decision path: 1.1.
2024-05-16 11:31:31,052:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:31:31,052:INFO: Solarflow is willing to contribute 114.0W (per channel) of the requested 228.2!
2024-05-16 11:31:31,052:INFO: Setting inverter output limit to 456W (1 min moving average of 114W x 4)
2024-05-16 11:31:31,053:INFO: Sun: 05:09 - 20:59 Demand: 228.2W, Panel DC: (0.0W), Hub DC: (224.4W), Inverter Limit: 456.0W, Hub Limit: 800.0W
2024-05-16 11:31:31,053:INFO: HUB triggers limit function: 658.2 -> 625.5: executed
2024-05-16 11:31:32,069:INFO: HUB triggers limit function: 655.0 -> 619.0: skipped
2024-05-16 11:31:34,128:INFO: HUB triggers limit function: 644.1 -> 608.8: skipped
2024-05-16 11:31:35,146:INFO: HUB triggers limit function: 637.2 -> 602.3: skipped
2024-05-16 11:31:36,163:INFO: HUB triggers limit function: 630.3 -> 595.8: skipped
2024-05-16 11:31:37,183:INFO: HUB triggers limit function: 623.5 -> 589.6: skipped
2024-05-16 11:31:38,202:INFO: HUB triggers limit function: 616.9 -> 583.5: skipped
2024-05-16 11:31:39,222:INFO: HUB triggers limit function: 610.4 -> 577.6: skipped
2024-05-16 11:31:40,240:INFO: HUB triggers limit function: 604.0 -> 571.8: skipped
2024-05-16 11:31:41,259:INFO: HUB: S:566.2W [ 699.1,699.1,648.9,629.3,597.8,566.2 ], B: 99% (100|99), V:53.3V (53.4|53.2), C: 280W, P:False (manual, possible), F:17.9h, E:198.6h, H:227W, L:800W
2024-05-16 11:31:41,259:INFO: INV: AC:225.3W, AC_Prediction: 225.3W, DC:237.1W, DC_prediction: 237.1W (0.0|0.0|121.8|118.3), L:448W (112.0W/channel) [1600W]
2024-05-16 11:31:41,261:INFO: SMT: T:ShellyEM3 P:-2.4W [ 11.4,11.4,12.9,12.7,12.6,9.8 ] Predict: 9.6W
2024-05-16 11:31:41,261:INFO: Direct connected panel are producing 0.0W, trying to get 227.9W from hub.
2024-05-16 11:31:41,261:INFO: Based on time, solarpower (566.2W) minimum charge power (0W) and bypass state (False), hub could contribute 227.9W - Decision path: 1.1.
2024-05-16 11:31:41,262:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:31:41,262:INFO: Solarflow is willing to contribute 113.5W (per channel) of the requested 227.9!
2024-05-16 11:31:41,262:INFO: Not setting inverter output limit as it is identical to current limit!
2024-05-16 11:31:41,262:INFO: Grid feed in from hub solarpower: 0.2W!
2024-05-16 11:31:41,262:INFO: Sun: 05:09 - 20:59 Demand: 227.9W, Panel DC: (0.0W), Hub DC: (228.1W), Inverter Limit: 452.0W, Hub Limit: 800.0W
2024-05-16 11:31:41,262:INFO: HUB triggers limit function: 597.8 -> 566.2: executed
2024-05-16 11:31:42,288:INFO: HUB triggers limit function: 591.6 -> 560.5: skipped
2024-05-16 11:31:43,302:INFO: HUB triggers limit function: 585.6 -> 555.0: skipped
2024-05-16 11:31:44,318:INFO: HUB triggers limit function: 579.7 -> 549.6: skipped
2024-05-16 11:31:51,510:INFO: Bypass control, turning on bypass!
2024-05-16 11:31:51,510:INFO: Turning hub bypass ON
2024-05-16 11:31:51,512:INFO: Reading last full time: 2024-05-16 11:31:51
2024-05-16 11:31:51,512:INFO: Reading battery target mode: discharging
2024-05-16 11:31:52,547:INFO: Rapid rise in demand detected, clearing buffer!
2024-05-16 11:31:52,548:INFO: HUB: S:514.9W [ 619.5,619.5,601.5,571.6,541.9,514.9 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 233W, P:False (manual, not possible), F:0.0h, E:198.6h, H:233W, L:800W
2024-05-16 11:31:52,551:INFO: INV: AC:229.9W, AC_Prediction: 224.1W, DC:242.0W, DC_prediction: 235.8W (0.0|0.0|122.5|118.8), L:448W (112.0W/channel) [1600W]
2024-05-16 11:31:52,551:INFO: SMT: T:ShellyEM3 P:227.3W [ 227.3,227.3,227.3 ] Predict: 227.3W
2024-05-16 11:31:52,551:INFO: Direct connected panel are producing 0.0W, trying to get 446.6W from hub.
2024-05-16 11:31:52,551:INFO: Based on time, solarpower (514.9W) minimum charge power (0W) and bypass state (False), hub could contribute 446.6W - Decision path: 1.1.
2024-05-16 11:31:52,551:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:31:52,551:INFO: Solarflow is willing to contribute 223.0W (per channel) of the requested 446.6!
2024-05-16 11:31:52,552:INFO: Setting inverter output limit to 892W (1 min moving average of 223W x 4)
2024-05-16 11:31:52,552:INFO: Sun: 05:09 - 20:59 Demand: 446.6W, Panel DC: (0.0W), Hub DC: (229.3W), Inverter Limit: 892.0W, Hub Limit: 800.0W
2024-05-16 11:31:52,552:INFO: SMT triggers limit function: 227.3 -> 227.3: executed
2024-05-16 11:31:54,365:INFO: HUB: S:507.9W [ 604.7,604.7,589.3,560.3,531.6,507.9 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 221W, P:False (manual, not possible), F:0.0h, E:198.6h, H:226W, L:800W
2024-05-16 11:31:54,370:INFO: INV: AC:231.0W, AC_Prediction: 224.1W, DC:243.1W, DC_prediction: 235.8W (0.0|0.0|126.0|122.3), L:448W (112.0W/channel) [1600W]
2024-05-16 11:31:54,370:INFO: SMT: T:ShellyEM3 P:227.3W [ 227.3,227.3 ] Predict: 227.3W
2024-05-16 11:31:54,370:INFO: Direct connected panel are producing 0.0W, trying to get 453.2W from hub.
2024-05-16 11:31:54,370:INFO: Based on time, solarpower (507.9W) minimum charge power (0W) and bypass state (False), hub could contribute 453.2W - Decision path: 1.1.
2024-05-16 11:31:54,370:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:31:54,370:INFO: Solarflow is willing to contribute 226.5W (per channel) of the requested 453.2!
2024-05-16 11:31:54,371:INFO: Setting inverter output limit to 904W (1 min moving average of 226W x 4)
2024-05-16 11:31:54,371:INFO: Sun: 05:09 - 20:59 Demand: 453.2W, Panel DC: (0.0W), Hub DC: (235.9W), Inverter Limit: 904.0W, Hub Limit: 800.0W
2024-05-16 11:31:54,387:INFO: Triggering telemetry update: iot/A8yh63/ETFTke36/properties/read
2024-05-16 11:31:56,812:INFO: Reading last full time: 2024-05-16 11:31:56
2024-05-16 11:31:56,812:INFO: Reading battery target mode: discharging
2024-05-16 11:32:02,928:INFO: HUB: S:438.3W [ 573.1,573.1,538.3,505.4,474.5,438.3 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 141W, P:False (manual, not possible), F:0.0h, E:198.6h, H: 84W, L:800W
2024-05-16 11:32:02,932:INFO: INV: AC:177.0W, AC_Prediction: 232.3W, DC:186.7W, DC_prediction: 244.4W (0.0|0.0|1.0|1.1), L:448W (112.0W/channel) [1600W]
2024-05-16 11:32:02,932:INFO: SMT: T:ShellyEM3 P:228.6W [ 228.0,228.0,228.2 ] Predict: 228.2W
2024-05-16 11:32:02,932:INFO: Direct connected panel are producing 0.0W, trying to get 218.2W from hub.
2024-05-16 11:32:02,933:INFO: Based on time, solarpower (438.3W) minimum charge power (0W) and bypass state (False), hub could contribute 218.2W - Decision path: 1.1.
2024-05-16 11:32:02,933:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:32:02,933:INFO: Solarflow is willing to contribute 109.0W (per channel) of the requested 218.2!
2024-05-16 11:32:02,933:INFO: Setting inverter output limit to 436W (1 min moving average of 109W x 4)
2024-05-16 11:32:02,933:INFO: Sun: 05:09 - 20:59 Demand: 218.2W, Panel DC: (0.0W), Hub DC: (0.0W), Inverter Limit: 436.0W, Hub Limit: 800.0W
2024-05-16 11:32:02,933:INFO: HUB triggers limit function: 474.5 -> 438.3: executed
2024-05-16 11:32:03,947:INFO: HUB triggers limit function: 462.0 -> 414.3: skipped
2024-05-16 11:32:04,973:INFO: HUB triggers limit function: 445.5 -> 389.2: skipped
2024-05-16 11:32:05,990:INFO: HUB triggers limit function: 428.4 -> 363.1: skipped
2024-05-16 11:32:07,004:INFO: HUB triggers limit function: 410.8 -> 336.0: skipped
2024-05-16 11:32:08,023:INFO: HUB triggers limit function: 392.9 -> 308.3: skipped
2024-05-16 11:32:09,047:INFO: HUB triggers limit function: 374.6 -> 279.8: skipped
2024-05-16 11:32:10,076:INFO: HUB triggers limit function: 356.0 -> 250.7: skipped
2024-05-16 11:32:11,079:INFO: HUB triggers limit function: 337.2 -> 221.1: skipped
2024-05-16 11:32:12,111:INFO: HUB triggers limit function: 318.1 -> 191.2: skipped
2024-05-16 11:32:13,122:INFO: HUB: S:161.3W [ 454.8,454.8,409.9,362.3,299.1,161.3 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 0W, P:False (manual, not possible), F:0.0h, E:198.6h, H: 14W, L:800W
2024-05-16 11:32:13,127:INFO: INV: AC:177.0W, AC_Prediction: 232.3W, DC:186.7W, DC_prediction: 244.4W (0.0|0.0|1.0|1.1), L:435W (108.8W/channel) [1600W]
2024-05-16 11:32:13,127:INFO: SMT: T:ShellyEM3 P:225.4W [ 228.1,228.1,228.3,228.5 ] Predict: 228.5W
2024-05-16 11:32:13,127:INFO: Direct connected panel are producing 0.0W, trying to get 218.5W from hub.
2024-05-16 11:32:13,127:INFO: Based on time, solarpower (161.3W) minimum charge power (0W) and bypass state (False), hub could contribute 161.3W - Decision path: 2.2.
2024-05-16 11:32:13,127:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:32:13,127:INFO: Solarflow is willing to contribute 80.5W (per channel) of the requested 218.5!
2024-05-16 11:32:13,127:INFO: Setting inverter output limit to 320W (1 min moving average of 80W x 4)
2024-05-16 11:32:13,128:INFO: Sun: 05:09 - 20:59 Demand: 218.5W, Panel DC: (0.0W), Hub DC: (0.0W), Inverter Limit: 320.0W, Hub Limit: 800.0W
2024-05-16 11:32:13,128:INFO: HUB triggers limit function: 299.1 -> 161.3: executed
2024-05-16 11:32:15,184:INFO: HUB triggers limit function: 270.7 -> 132.9: skipped
2024-05-16 11:32:16,219:INFO: HUB triggers limit function: 251.8 -> 128.4: skipped
2024-05-16 11:32:17,215:INFO: HUB triggers limit function: 233.3 -> 124.8: skipped
2024-05-16 11:32:19,230:INFO: HUB triggers limit function: 202.7 -> 108.5: skipped
2024-05-16 11:32:20,245:INFO: HUB triggers limit function: 184.5 -> 107.1: skipped
2024-05-16 11:32:21,260:INFO: HUB triggers limit function: 166.6 -> 106.2: skipped
2024-05-16 11:32:21,563:INFO: Rapid drop in demand detected, clearing buffer!
2024-05-16 11:32:21,563:INFO: HUB: S:106.2W [ 378.0,378.0,324.2,262.7,166.6,106.2 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 0W, P:False (manual, not possible), F:0.0h, E:198.6h, H: 0W, L:800W
2024-05-16 11:32:21,567:INFO: INV: AC:177.0W, AC_Prediction: 232.3W, DC:186.7W, DC_prediction: 244.4W (0.0|0.0|1.0|1.1), L:435W (108.8W/channel) [1600W]
2024-05-16 11:32:21,567:INFO: SMT: T:ShellyEM3 P:-112.2W [ -112.2,-112.2,-112.2 ] Predict: -112.2W
2024-05-16 11:32:21,567:INFO: Direct connected panel are producing 0.0W, trying to get 0.0W from hub.
2024-05-16 11:32:21,567:INFO: Based on time, solarpower (106.2W) minimum charge power (0W) and bypass state (False), hub could contribute  0.0W - Decision path: 1.1.
2024-05-16 11:32:21,567:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:32:21,567:INFO: Solarflow is willing to contribute 0.0W (per channel) of the requested 0.0!
2024-05-16 11:32:21,567:INFO: Setting inverter output limit to 40W (1 min moving average of 10W x 4)
2024-05-16 11:32:21,567:INFO: Grid feed in from unknown: 122.2!
2024-05-16 11:32:21,568:INFO: Sun: 05:09 - 20:59 Demand: -122.2W, Panel DC: (0.0W), Hub DC: (0.0W), Inverter Limit: 40.0W, Hub Limit: 800.0W
2024-05-16 11:32:21,568:INFO: SMT triggers limit function: -112.2 -> -112.2: executed
2024-05-16 11:32:22,281:INFO: HUB triggers limit function: 149.3 -> 99.4: skipped
2024-05-16 11:32:23,295:INFO: HUB triggers limit function: 132.7 -> 94.7: skipped
2024-05-16 11:32:24,560:INFO: Rapid rise in demand detected, clearing buffer!
2024-05-16 11:32:24,560:INFO: HUB: S:92.4W [ 348.0,348.0,297.6,224.5,117.8,92.4 ], B:100% (100|100), V:53.3V (53.4|53.2), C: 0W, P:False (manual, not possible), F:0.0h, E:198.6h, H:127W, L:800W
2024-05-16 11:32:24,564:INFO: INV: AC:177.0W, AC_Prediction: 232.3W, DC:186.7W, DC_prediction: 244.4W (0.0|0.0|1.0|1.1), L:1600W (400.0W/channel) [1600W]
2024-05-16 11:32:24,564:INFO: SMT: T:ShellyEM3 P:211.8W [ 211.8,211.8 ] Predict: 211.8W
2024-05-16 11:32:24,564:INFO: Direct connected panel are producing 0.0W, trying to get 201.8W from hub.
2024-05-16 11:32:24,564:INFO: Based on time, solarpower (92.4W) minimum charge power (0W) and bypass state (False), hub could contribute 92.4W - Decision path: 2.2.
2024-05-16 11:32:24,564:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:32:24,564:INFO: Solarflow is willing to contribute 46.0W (per channel) of the requested 201.8!
2024-05-16 11:32:24,565:INFO: Setting inverter output limit to 184W (1 min moving average of 46W x 4)
2024-05-16 11:32:24,565:INFO: Sun: 05:09 - 20:59 Demand: 201.8W, Panel DC: (0.0W), Hub DC: (0.0W), Inverter Limit: 184.0W, Hub Limit: 800.0W
2024-05-16 11:32:24,565:INFO: SMT triggers limit function: 211.8 -> 211.8: executed
2024-05-16 11:32:35,559:INFO: Reading last full time: 2024-05-16 11:32:35
2024-05-16 11:32:35,600:INFO: Reading battery target mode: discharging
2024-05-16 11:32:37,581:INFO: HUB: S:160.5W [ 259.5,259.5,194.9,143.2,130.3,160.5 ], B:100% (100|100), V:52.8V (53.0|52.6), C: 0W, P:False (manual, not possible), F:0.0h, E:198.6h, H:196W, L:800W
2024-05-16 11:32:37,585:INFO: INV: AC:177.0W, AC_Prediction: 232.3W, DC:186.7W, DC_prediction: 244.4W (0.0|0.0|1.0|1.1), L:184W (46.0W/channel) [1600W]
2024-05-16 11:32:37,585:INFO: SMT: T:ShellyEM3 P:143.6W [ 184.7,184.7,182.1,172.8 ] Predict: 172.8W
2024-05-16 11:32:37,585:INFO: Direct connected panel are producing 0.0W, trying to get 162.8W from hub.
2024-05-16 11:32:37,585:INFO: Based on time, solarpower (160.5W) minimum charge power (0W) and bypass state (False), hub could contribute 160.5W - Decision path: 2.2.
2024-05-16 11:32:37,585:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-05-16 11:32:37,585:INFO: Solarflow is willing to contribute 80.0W (per channel) of the requested 162.8!
2024-05-16 11:32:37,585:INFO: Setting inverter output limit to 320W (1 min moving average of 80W x 4)
2024-05-16 11:32:37,586:INFO: Sun: 05:09 - 20:59 Demand: 162.8W, Panel DC: (0.0W), Hub DC: (0.0W), Inverter Limit: 320.0W, Hub Limit: 800.0W

Funnily, the switch in HA did move and based on what my hub does, I know it was in BP mode. However, the app never understood this. It also did not understand this hours later. The switch in HA does work for me, I can see differences when I toggle it, so its not that the switch tricks me... My config is set to let the app regulate the BP mode, which also works fine. This is what I can tell. I am also running latest master. But as said, the app does not know this, somehow...

I sadly do not have the states from MQTT, as I am not at home atm and only can retrospectively check the logs from the app. How does the app read the BP mode from the hub? Is there maybe anything wrong configured on my end? What data can I provide so that you can investigate this a bit more?

Best, MaVo

mavo commented 5 months ago

New day, new comment 🙈 I played around a bit more in an effort to fix this issue for me locally, but had no success as of yet. To me, it seems almost clear, that my hub2k does not report pass = 1 in MQTT, although its in BP mode. So there is one question @floriandrott - do you have a hub2000or the older hub1200? What I've tried is by modifying the source code in the container to set the BP state when it reaches 100% battery and keep this value. However, as there is the telemetry update every now ad then, the manual set value is lost after 2 mins again and is replaced by pass = 0. The question is, does the hub2k for some reason set this value somewhat differently?

It's super annoying for me, as my battery is currently full at around 2pm due to sunshine without any cloud, but I still use some power from the grid as soon as the BP is on due to the fact that the app does not know and the other logic in the app eventually reduces the inverter ever so slightly every now and then which leads to the situation, that the hub cannot feed more, therefore reduces what it provides and the app, as it has no clue about BP and does not want to take something from the battery so it reduces the inverter even more.

Any help would be great 😢

reinhard-brandstaedter commented 5 months ago

What are your BP settings in the Zendure app? Does the BP kick in if you do not control it via sf-control?

floriandrott commented 5 months ago

@mavo I use the hub2000 in my setup.

Yes @reinhard-brandstaedter, BP kicks in automatically if the battery reaches 100% and I see as @mavo that the switch in HA is turned on for BP.

The setting in the Zendure app for BP is "always on" / "always off" depending if BP kicked in or not.

reinhard-brandstaedter commented 5 months ago

The pass property is just read like any other property of the hub. I can’t see any reason why it should not be reflected in the logs then. So it would be really helpful to know what the state in MQTT is.

mavo commented 5 months ago

@reinhard-brandstaedter the BP actually kicks in. I kinda assume it's reported differently compared to hub1200. But as I can only access my HA and the logs via ssh but not mqtt I cannot tell the mqtt values. However, in one of the first comments of @floriandrott here you can see that "pass" is reported as 0 always.

@reinhard-brandstaedter how did you first discover the values and properties and how they are reported in mqtt, did you just check what the hub emitted and deducted what is useful?

floriandrott commented 5 months ago

@reinhard-brandstaedter I can check the MQTT changes. Any specific values on which I should pay attention when the battery reaches 100%? I will then check via MQTT Explorer the next time (hopefully today).

floriandrott commented 5 months ago

@reinhard-brandstaedter I reached again 100% battery. Hub2000 is in BP mode (but still solarflow-control is reporting BP=false). In MQTT following values have changed:

passMode=1 to passMode=2
packState=1 to packState=0

mavo commented 5 months ago

@floriandrott "packState" is the indicator, if the battery is idle, charging or discharging. So this is not the value we are looking for...

But I don't know enough to say where to look. Good thing, I am back home and can check mqtt values as well :-)

mavo commented 5 months ago

Quick thought @reinhard-brandstaedter, if we do not find how the BP state is transferred in Hub2k when manual mode is used, wouldn't it be an option to use the logic of the passMode as indicator if the BP is on? I mean, as the app controls it, setting the value to the equal of "always on" / "always off" is defining in which state it is. So if you would change the "hub.getBypass()" method to check (pseudo-code incoming)

if hub.productId == "hub2k" and sf-app.BpControl
  return passMode == 2
else
  return pass = 1

This approach assumes that the pass property is not set when passMode != 0. I will try to check, but the forecast is not very great atm, so lets see when I can test it actually. Maybe @floriandrott can check it as well (setting sf-control to not rule the BP mode but rather use auto and let the hubs firmware decide).

floriandrott commented 5 months ago

@mavo alright, I will check it as well. I switched off control_bypass and enabled auto in the Zendure app for BP. Let's see what happens.

floriandrott commented 5 months ago

@mavo no change here. The log says HUB: S:47.6W [ 61.0,61.0,54.5,52.4,49.5,47.6 ], B:100% (100), V:53.6V (53.6), C: 39W, P:False (auto, possible), F:0.0h, E:55.8h, H: 0W, L:600W

I saw also a strange behavior from the hub BP logic. 100% reached and afterwards the battery was discharging and charging which isn't the correct BP behavior. I turned on BP manually.

mavo commented 5 months ago

Thanks for testing.

And in this case, I hope that @reinhard-brandstaedter would be so kind to implement something in the direction that I mentioned 😇

reinhard-brandstaedter commented 5 months ago

@mavo @floriandrott the problem I see with BP Mode is that it is a intent to switch only. The hubs firware decides when it really performs the switch. Just because bypassmode is 2, still doesn’t mean it is actuslly on. I think the slow switchting/no switching even in auto mode also confirms this.

mavo commented 5 months ago

But what then? Just do nothing? Not really a good option I'd say.

Imo, the PassMode is the best we can do. Currently it's kinda broken. Why do you think it's bad to use the PassMode? What's the difference for the app? The PassMode should indicate where it should (and mostly will be) in a short time...

reinhard-brandstaedter commented 5 months ago

I honestly doubt that the firmware is differen in this regard. Why should everything work identical, just the pass telemetry is reported in a different way. I’d further investigate this what really is differen on the hub side. Eventually its even a bug on SF side. Plus we haven’t a precise observation from the MQTT publish topic at the time of switching to BP yet.

mavo commented 5 months ago

What kind of recording can I provide? I have no good explanation why it behaves differently for the hub2k, the only thing I can tell is that it does. Maybe it's a bug in the firmware, but there is no update available and only God knows when there will be one.

If you tell me what kind of data I should record, I can try to do, when the conditions are good.

For the meantime I probably will change the code locally to use the passMode property in am effort to not just be stuck while we try to find the proper solution.

reinhard-brandstaedter commented 5 months ago

All variables reported to MQTT would be interesting. e.g by keeping MQTT explorer open for a few hours and collect the topic tree reported by sf-control. And then a history of the pass topic before and after the expected BP switch.

floriandrott commented 5 months ago

@reinhard-brandstaedter I have no clue how to store the data in MQTT Explorer so I used a different tool to collect the MQTT topic data. I subscripted for the sf-control data solarflow-hub and for the raw data from the hub /A8yh63/XXXXXXXX/properties/report.

Battery reached at 18:25:40 100% and the hub went into BP mode. Attached are two files (one 10min data after the switch and one with +20min data after the switch).

data.json data2.json

I hope this helps to find out more about the hub behavior. Please let me know if I can provide anything else to troubleshoot.

reinhard-brandstaedter commented 5 months ago

Thanks, that confirms that the hub2000 doesn't report the bypass state via the pass topic. When switched to passMode : 2 it reduces the solarinput down to 0, just like the hub1200 enables BP silently and then turns on solarinput again. So for hub2000 one can only assume that BP is on if all these conditions are met passMode == 2 & solarInput > 0 & outputPackPower == 0 & outputHomePower > 0. What a bummer!

floriandrott commented 5 months ago

@reinhard-brandstaedter thank you for the changes. I was testing it with the latest DEV build but BP wasn't recognized from sf-control.

The MQTT topic logs are attached here: data3.json

The battery reached 100% and the hub went into BP mode. But sf-control was still reporting BP=false

2024-05-23 18:56:45,856:INFO: HUB: S:337.2W [ 351.7,351.7,350.4,343.6,340.2,337.2 ], B: 98% (98), V:51.9V (51.9), C: 231W, P:False (manual, possible), F:0.5h, E:130.3h, H: 92W, L:600W
2024-05-23 18:56:56,013:INFO: Bypass control, turning on bypass!
2024-05-23 18:56:56,013:INFO: Turning hub bypass ON
2024-05-23 18:56:56,014:INFO: Reading last full time: 2024-05-23 18:56:56
2024-05-23 18:56:56,015:INFO: Reading battery target mode: discharging
2024-05-23 18:57:05,919:INFO: HUB: S:293.5W [ 322.8,322.8,315.1,308.1,300.6,293.5 ], B:100% (100), V:51.9V (51.9), C: 143W, P:False (manual, not possible), F:0.0h, E:130.3h, H: 67W, L:600W

In addition I got also following error in the sf-control logs

    self.run()
  File "/usr/local/lib/python3.11/threading.py", line 1401, in run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/utils.py", line 25, in _run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/solarflow-control.py", line 418, in deviceInfo
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

Any idea why?

mavo commented 5 months ago

The exception I had as well. For me it was thrown when BP should have been disabled as the sun was covered by clouds and it was already passed the sun - offset point.

I guess.the log line reads BP from pass property, but based on the decision path you can see when it was used. The decision path starts with a 0 in case BP mode is determined by SF control.

reinhard-brandstaedter commented 5 months ago

Because Hub2k does not only NOT report the bypass state properly, but it reports it even wrong, I still pushes pass=0 even though it is in bypass.... passMode = 2 is still just a intent, and eventually at some point the BP is on, but this is somewhat guesswork.

reinhard-brandstaedter commented 5 months ago

This: 2024-05-23 18:56:56,013:INFO: Turning hub bypass ON sends the hub the intent to turn bypass on. Then the hub takes a bit to really turn it on, but then sends a pass=0 which sf-control again interprets as BP is off. Finally when sf-control is able to determine by other means that the BP has kicked in, there could be another update to pass=0 which makes sf-control again think it is off. So the only way to guess the true BP state is to completely ignore pass and use passMode == 2 & solarInput > 0 & outputPackPower == 0 (hub has solarinput but doesn't charge the battery and has the passmode set - even outputHome seems to be 0 at this time). However this could also be true before the actual switch has happened.

Overall, bypass control on hub2k is not as precise as on hub1200

Try again tomorrow with a new build

mavo commented 5 months ago

@reinhard-brandstaedter with the change to recognize the hub2k's weird BP state, I think the code needs a bit more adjustment.

The logic to leave the BP when time is right and demand is higher than supplied energy does not set the passMode, or at least I don't see how it's done.

This seems to be the reason why @floriandrott and I saw the exception thrown that the limit variable was not set. This is in the decision path 0.1, where it does not set any new limit, but as the following condition if the hub is not in BP anymore is not true for the hub2k, limit is never set therefore python rightfully complains.

welli2009 commented 5 months ago

It works for me now, I simply wrote a Homeassistant automation that sets the inverter limit to 100% as soon as the hub has reached 100% and passMode 2 has been published. This is repeated every 2 seconds until two hours before sunset or until passMode 1 is published.

floriandrott commented 5 months ago

@reinhard-brandstaedter today I was able to test the bypass mode again. Finally turning on BP worked 🥳 Thank you.

sf-control switched to bypass mode ON:

2024-05-26 16:40:45,997:INFO: HUB: S:175.7W [ 191.5,191.5,193.6,191.8,183.2,175.7 ], B: 98% (98), V:52.4V (52.4), C: 140W, P:False (manual, possible), F:68.5h, E:200.0h, H: 14W, L:600W
2024-05-26 16:40:45,997:INFO: INV: AC:25.0W, DC:26.3W (12.0|13.0), L: 20W (10.0W/channel) [800W]
2024-05-26 16:40:45,998:INFO: Based on time, solarpower (175.7W) minimum charge power (290W) and bypass state (False), hub could contribute  0.0W - Decision path: 2.2.
2024-05-26 16:41:00,974:INFO: Bypass control, turning on bypass!
2024-05-26 16:41:00,974:INFO: Turning hub bypass ON
2024-05-26 16:41:00,974:INFO: Reading last full time: 2024-05-26 16:41:00
2024-05-26 16:41:01,015:INFO: Reading battery target mode: discharging
2024-05-26 16:41:07,470:INFO: HUB: S:143.0W [ 177.4,177.4,172.2,160.8,146.8,143.0 ], B:100% (100), V:53.3V (53.3), C: 113W, P:False (manual, not possible), F:0.0h, E:200.0h, H: 0W, L:600W
2024-05-26 16:41:07,470:INFO: INV: AC:23.4W, DC:24.6W (7.8|8.7), L: 20W (10.0W/channel) [800W]
2024-05-26 16:41:07,470:INFO: Based on time, solarpower (143.0W) minimum charge power (290W) and bypass state (False), hub could contribute  0.0W - Decision path: 2.2.

The bypass state in the last log message isn't correct but in the next one it is :)

2024-05-26 16:42:02,031:INFO: HUB: S:41.5W [ 43.9,43.9,33.4,29.3,34.1,41.5 ], B:100% (100), V:52.7V (52.7), C: 0W, P:False (manual, not possible), F:0.0h, E:200.1h, H: 0W, L:600W
2024-05-26 16:42:02,032:INFO: Based on time, solarpower (41.5W) minimum charge power (290W) and bypass state (True), hub could contribute 600.0W - Decision path: 0.2.

The log message about the HUB information still says for BP false but I assume that's correct due to our workaround.

Unfortunately there is an issue for turning bypass OFF: sf-control turned off BP and then I got the following error:

2024-05-26 18:38:24,972:INFO: Turning hub bypass OFF
Traceback (most recent call last):
  File "/solarflow/solarflow-control.py", line 513, in <module>
    main(sys.argv[1:])
  File "/solarflow/solarflow-control.py", line 510, in main
    run()
  File "/solarflow/solarflow-control.py", line 448, in run
    client.loop_forever()
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
         ^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
         ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle
    return self._handle_publish()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish
    self._handle_on_message(message)
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message
    on_message(self, self._userdata, message)
  File "/solarflow/solarflow-control.py", line 133, in on_message
    smartmeter.handleMsg(msg)
  File "/solarflow/smartmeters.py", line 95, in handleMsg
    self.updPower()
  File "/solarflow/smartmeters.py", line 79, in updPower
    log.info(f'SMT triggers limit function: {previous} -> {self.getPower()}: {"executed" if self.trigger_callback(self.client,force=force_trigger) else "skipped"}')
                                                                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 408, in limit_callback
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

And then following error message is recurring:

2024-05-26 18:39:07,488:INFO: Turning hub bypass OFF
Exception in thread Thread-597:
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.11/threading.py", line 1401, in run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/utils.py", line 25, in _run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/solarflow-control.py", line 418, in deviceInfo
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

Due to this error sf-control is sending the maximum possible energy to the house without respecting the real consumption.

Anything what I can do to help?

floriandrott commented 5 months ago

@reinhard-brandstaedter I updated to the last DEV build.

Here I saw that something is wrong with the detected BP mode by the hub: 2024-05-27 15:04:49,095:INFO: HUB: S:289.3W [ 317.1,317.1,313.2,301.9,293.7,289.3 ], B: 64% (64), V:50.3V (50.3), C: 256W, P:True (manual, possible), F:20.4h, E:222.4h, H: 13W, L:600W

P=True but this isn't correct. I double-checked the MQTT value and here sf-control is reporting passMode=1 and also the battery is charging.

floriandrott commented 5 months ago

@reinhard-brandstaedter I'm unsure if you changed something in regards of the UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value issue in the DEV version from today. Just to let you know that I had this error again this evening.

reinhard-brandstaedter commented 5 months ago

The BP mode not displayed in the log is more/less just a presentation problem (accessor not used that differentiates between hub2k and hub1.2k, fixed that. The problem with the unbound variable hopefully shouldn't happen anymore, the hub2k special handling led to some kind of race condition with MQTT updates...that's the problem with the non-reliable state of the hub2k.

floriandrott commented 5 months ago

@reinhard-brandstaedter yesterday I had the issue with the variable again. When the error occurs then somehow sf-control stops working and the battery gets discharged rapidly because the inverter limit stays with 600W (max value due to BP). Somehow the BP gets as well deactivated due to the issue so that the battery is discharging. I had expected if BP on and not enough solarpower is available, then the battery gets not discharged until BP is turned off.

floriandrott commented 5 months ago

@reinhard-brandstaedter I was looking today a bit more into the error of the variable.

I have the setting configured that sunset is 95 minutes earlier. When sf-control is switching to night mode then the error occurs.

2024-05-30 19:37:41,019:INFO: HUB: S:23.7W [ 23.7,23.7 ], B:100% (100), V:50.6V (50.6), C: 0W, P:True (manual, not possible), F:0.0h, E:299.0h, H: 0W, L:600W
2024-05-30 19:37:41,020:INFO: INV: AC:15.8W, DC:1.8W (0.4|1.3), L:600W (300.0W/channel) [800W]
2024-05-30 19:37:41,020:INFO: SMT: T:Smartmeter P:175.0W [ 170.4,170.4,168.6,166.5,159.5,177.0 ]
2024-05-30 19:37:41,020:INFO: Direct connected panel are producing 0.0W, trying to get 137.0W from hub.
2024-05-30 19:37:41,020:INFO: Turning hub bypass OFF
Traceback (most recent call last):
  File "/solarflow/solarflow-control.py", line 513, in <module>
    main(sys.argv[1:])
  File "/solarflow/solarflow-control.py", line 510, in main
    run()
  File "/solarflow/solarflow-control.py", line 448, in run
    client.loop_forever()
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
         ^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
         ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle
    return self._handle_publish()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish
    self._handle_on_message(message)
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message
    on_message(self, self._userdata, message)
  File "/solarflow/solarflow-control.py", line 133, in on_message
    smartmeter.handleMsg(msg)
  File "/solarflow/smartmeters.py", line 95, in handleMsg
    self.updPower()
  File "/solarflow/smartmeters.py", line 79, in updPower
    log.info(f'SMT triggers limit function: {previous} -> {self.getPower()}: {"executed" if self.trigger_callback(self.client,force=force_trigger) else "skipped"}')
                                                                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 408, in limit_callback
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
                                                                                                                                                                         ^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

With the next update interval the error goes to:

2024-05-30 19:37:42,960:INFO: Triggering telemetry update: iot/A8yh63/XXXXXXX/properties/read
2024-05-30 19:38:42,960:INFO: Triggering telemetry update: iot/A8yh63/XXXXXXX/properties/read
2024-05-30 19:38:42,993:INFO: HUB: S:23.7W [ 23.7,23.7 ], B:100% (100), V:50.6V (50.6), C: 0W, P:False (manual, not possible), F:0.0h, E:299.0h, H: 0W, L:600W
2024-05-30 19:38:42,993:INFO: INV: AC:15.8W, DC:1.8W (0.4|1.3), L:600W (300.0W/channel) [800W]
2024-05-30 19:38:42,993:INFO: SMT: T:Smartmeter P:175.0W [ 170.4,170.4,168.6,166.5,159.5,177.0 ]
2024-05-30 19:38:42,993:INFO: Direct connected panel are producing 0.0W, trying to get 137.0W from hub.
2024-05-30 19:38:42,994:INFO: Turning hub bypass OFF
Exception in thread Thread-9:
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.11/threading.py", line 1401, in run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/utils.py", line 25, in _run
    self.function(*self.args, **self.kwargs)
  File "/solarflow/solarflow-control.py", line 418, in deviceInfo
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
                                                                                                                                                                         ^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

These messages are coming after update interval of sf-control. I manually restarted sf-control and I got directly the same error after the first update interval. This time I had no rapidly discharge of the battery. The inverter limit was set to 100W and sf-control wasn't changing this anymore. I manually adjusted the inverter limit via OpenDTU and recognized that sf-control is not touching anymore the inverter limit.

2024-05-30 19:46:00,514:INFO: Reading last full time: 2024-05-30 19:46:00
2024-05-30 19:46:00,514:INFO: Reading battery target mode: discharging
2024-05-30 19:46:17,434:INFO: Determined inverter's max capacity: 800.0
2024-05-30 19:46:21,011:INFO: HUB: S:107.5W [ 118.7,118.7,107.5 ], B:100% (100), V:51.9V (51.9), C: 0W, P:True (manual, not possible), F:0.0h, E:299.1h, H: 0W, L:600W
2024-05-30 19:46:21,011:INFO: INV: AC:33.4W, DC:35.5W (0.1|0.4), L:100W (50.0W/channel) [800W]
2024-05-30 19:46:21,011:INFO: SMT: T:Smartmeter P:250.0W [ 231.7,231.7,254.8 ]
2024-05-30 19:46:21,011:INFO: Direct connected panel are producing 0.0W, trying to get 214.8W from hub.
2024-05-30 19:46:21,013:INFO: Turning hub bypass OFF
Traceback (most recent call last):
  File "/solarflow/solarflow-control.py", line 513, in <module>
    main(sys.argv[1:])
  File "/solarflow/solarflow-control.py", line 510, in main
    run()
  File "/solarflow/solarflow-control.py", line 448, in run
    client.loop_forever()
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1756, in loop_forever
    rc = self._loop(timeout)
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1164, in _loop
    rc = self.loop_read()
         ^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 1556, in loop_read
    rc = self._packet_read()
         ^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 2439, in _packet_read
    rc = self._packet_handle()
         ^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3033, in _packet_handle
    return self._handle_publish()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3327, in _handle_publish
    self._handle_on_message(message)
  File "/opt/venv/lib/python3.11/site-packages/paho/mqtt/client.py", line 3570, in _handle_on_message
    on_message(self, self._userdata, message)
  File "/solarflow/solarflow-control.py", line 133, in on_message
    smartmeter.handleMsg(msg)
  File "/solarflow/smartmeters.py", line 95, in handleMsg
    self.updPower()
  File "/solarflow/smartmeters.py", line 79, in updPower
    log.info(f'SMT triggers limit function: {previous} -> {self.getPower()}: {"executed" if self.trigger_callback(self.client,force=force_trigger) else "skipped"}')
                                                                                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 414, in limit_callback
    limitHomeInput(client)
  File "/solarflow/solarflow-control.py", line 342, in limitHomeInput
    sf_contribution = getSFPowerLimit(hub,hub_contribution_ask)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/solarflow/solarflow-control.py", line 257, in getSFPowerLimit
    log.info(f'Based on time, solarpower ({hub_solarpower:4.1f}W) minimum charge power ({MIN_CHARGE_POWER}W) and bypass state ({hub.getBypass()}), hub could contribute {limit:4.1f}W - Decision path: {path}')
                                                                                                                                                                         ^^^^^
UnboundLocalError: cannot access local variable 'limit' where it is not associated with a value

Now I was wondering when the error goes away .... at 20.30 I restarted again manually sf-control and then it was detected that the battery is by 97%.

2024-05-30 20:12:17,000:INFO: HUB: S:10.5W [ 10.5,10.5 ], B: 97% (97), V:49.6V (49.6), C:-143W, P:True (manual, possible), F:0.4h, E:299.6h, H:148W, L:600W

And now the error is gone and sf-control works again. I assume that only when the battery drops at least one percentage (battery < 100%) the error goes away. For the detection of the correct electricalLevel a restart of sf-control is required.

Anything how I can help more?

reinhard-brandstaedter commented 5 months ago

The responsible code for that behavior is here:

    if hub.getBypass():
        path += "0."
        # leave bypass after sunset/offset
        if (now < (sunrise + sunrise_off) or now > sunset - sunset_off) and hub.control_bypass and demand > hub_solarpower:
            hub.allowBypass(False)
            hub.setBypass(False)
            path += "1."
        else:
            path += "2."
            limit = hub.getInverseMaxPower()

    if not hub.getBypass():
        if hub_solarpower - demand > MIN_CHARGE_POWER:
            path += "1." 
            if hub_solarpower - MIN_CHARGE_POWER < MAX_DISCHARGE_POWER:
                path += "1."
                limit = min(demand,MAX_DISCHARGE_POWER)
            else:
                path += "2."
                limit = min(demand,hub_solarpower - MIN_CHARGE_POWER)
        if hub_solarpower - demand <= MIN_CHARGE_POWER:  
            path += "2."
            if (now < (sunrise + sunrise_off) or now > sunset - sunset_off): 
                path += "1."                
                limit = min(demand,MAX_DISCHARGE_POWER)
            else:
                path += "2."  
                #limit = 0 if hub_solarpower - MIN_CHARGE_POWER < 0 and hub.getElectricLevel() < 100 else hub_solarpower - MIN_CHARGE_POWER                                   
                limit = 0 if hub_solarpower - MIN_CHARGE_POWER < 0 else hub_solarpower - MIN_CHARGE_POWER
        if demand < 0:
            limit = 0

However I can't see why limit would not be set in any of those execution paths. I had this same error when I added the method calls for bypass determination on Hub2k, but with the recent change I haven't had it in the past days. Though with the current weather I only reached bypass twice....

mavo commented 5 months ago

Isn't path 0.1 open to have the limit variable not set, in case the BP switch is not fast enough? In this case, the BP mode is still on when it enters the part of the code (path 0) and realizes it needs to leave BP (path 0.1).

If the BP mode is then not updated before it reaches the 'not hub.getByPass' part it will not set a value onto the limit var, making it undefined.

Or is it me not understanding python again?

reinhard-brandstaedter commented 5 months ago

The subsequent getBypass() after path 0.1 should now also return false if the hub's state hasn't changed yet (using the internal bypass state of the solarflow class now. However if the hub2000 for some reason will not "accept" the switch we are working on a wrong state ... lets see how this proves in reality.

mavo commented 5 months ago

Hello @reinhard-brandstaedter, I pulled the latest dev from yesterday...

Now I see this:

2024-06-02 05:31:30,939:INFO: Triggering telemetry update: iot/A8yh63/ETFTke36/properties/read
2024-06-02 05:31:30,987:INFO: HUB: S:188.6W [ 224.0,224.0,220.0,206.1,195.5,188.6 ], B: 18% (18|18), V:48.6V (48.6|48.6), C:-111W, P:True (manual, possible), F:12.0h, E:49.4h, H:288W, L:800W
2024-06-02 05:31:30,988:INFO: INV: AC:286.1W, DC:301.0W (0.0|0.0|152.3|147.4), L:579W (144.8W/channel) [1600W]
2024-06-02 05:31:30,988:INFO: SMT: T:ShellyEM3 P:24.2W [ 12.2,12.2,12.8,13.9,15.8,15.4 ]
2024-06-02 05:31:30,988:INFO: Direct connected panel are producing 0.0W, trying to get 290.2W from hub.
2024-06-02 05:31:30,988:INFO: Turning hub bypass OFF
2024-06-02 05:31:30,989:INFO: Based on time, solarpower (188.6W) minimum charge power (0W) and bypass state (False), hub could contribute 290.2W - Decision path: 0.1.2.1.
2024-06-02 05:31:30,989:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:31:30,989:INFO: Solarflow is willing to contribute 145.0W (per channel) of the requested 290.2!
2024-06-02 05:31:30,989:INFO: Not setting inverter output limit as it is identical to current limit!
2024-06-02 05:31:30,989:INFO: Sun: 04:50 - 21:22 Demand: 290.2W, Panel DC: (0.0W), Hub DC: (284.8W), Inverter Limit: 580.0W, Hub Limit: 800.0W
2024-06-02 05:32:10,379:INFO: HUB: S:175.0W [ 185.3,185.3,180.5,177.6,176.5,175.0 ], B: 18% (18|18), V:48.6V (48.6|48.6), C:-117W, P:True (manual, not possible), F:12.0h, E:49.4h, H:287W, L:800W
2024-06-02 05:32:10,379:INFO: INV: AC:287.8W, DC:303.0W (0.0|0.0|154.5|149.6), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:10,379:INFO: SMT: T:ShellyEM3 P:130.9W [ 22.0,22.0,22.7,25.6,29.8,46.2 ]
2024-06-02 05:32:10,379:INFO: Direct connected panel are producing 0.0W, trying to get 325.1W from hub.
2024-06-02 05:32:10,380:INFO: Turning hub bypass OFF
2024-06-02 05:32:10,380:INFO: Based on time, solarpower (175.0W) minimum charge power (0W) and bypass state (False), hub could contribute 325.1W - Decision path: 0.1.2.1.
2024-06-02 05:32:10,380:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:10,380:INFO: Solarflow is willing to contribute 162.5W (per channel) of the requested 325.1!
2024-06-02 05:32:10,380:INFO: Setting inverter output limit to 648W (1 min moving average of 162W x 4)
2024-06-02 05:32:10,380:INFO: Sun: 04:50 - 21:22 Demand: 325.1W, Panel DC: (0.0W), Hub DC: (288.9W), Inverter Limit: 648.0W, Hub Limit: 800.0W
2024-06-02 05:32:10,380:INFO: SMT triggers limit function: 29.8 -> 46.2: executed
2024-06-02 05:32:10,382:INFO: SMT triggers limit function: 31.5 -> 48.8: skipped
2024-06-02 05:32:10,384:INFO: SMT triggers limit function: 33.1 -> 51.3: skipped
2024-06-02 05:32:12,393:INFO: SMT triggers limit function: 35.4 -> 60.4: skipped
2024-06-02 05:32:12,395:INFO: SMT triggers limit function: 37.0 -> 62.6: skipped
2024-06-02 05:32:12,397:INFO: SMT triggers limit function: 38.0 -> 63.7: skipped
2024-06-02 05:32:12,855:INFO: SMT triggers limit function: 39.7 -> 64.8: skipped
2024-06-02 05:32:12,857:INFO: SMT triggers limit function: 40.8 -> 65.9: skipped
2024-06-02 05:32:12,859:INFO: SMT triggers limit function: 41.8 -> 66.8: skipped
2024-06-02 05:32:14,402:INFO: SMT triggers limit function: 43.6 -> 75.0: skipped
2024-06-02 05:32:14,403:INFO: SMT triggers limit function: 44.5 -> 75.6: skipped
2024-06-02 05:32:14,405:INFO: SMT triggers limit function: 45.5 -> 76.4: skipped
2024-06-02 05:32:16,415:INFO: SMT triggers limit function: 50.4 -> 85.2: skipped
2024-06-02 05:32:16,416:INFO: SMT triggers limit function: 51.3 -> 85.8: skipped
2024-06-02 05:32:16,418:INFO: SMT triggers limit function: 52.2 -> 86.1: skipped
2024-06-02 05:32:16,817:INFO: SMT triggers limit function: 55.0 -> 89.7: skipped
2024-06-02 05:32:16,818:INFO: SMT triggers limit function: 57.8 -> 93.1: skipped
2024-06-02 05:32:16,821:INFO: SMT triggers limit function: 60.6 -> 96.5: skipped
2024-06-02 05:32:18,426:INFO: SMT triggers limit function: 69.1 -> 109.0: skipped
2024-06-02 05:32:18,428:INFO: SMT triggers limit function: 72.0 -> 112.1: skipped
2024-06-02 05:32:18,429:INFO: SMT triggers limit function: 74.7 -> 115.0: skipped
2024-06-02 05:32:20,438:INFO: HUB: S:172.4W [ 180.3,180.3,177.0,175.2,174.1,172.4 ], B: 18% (18|18), V:48.6V (48.6|48.6), C:-143W, P:True (manual, not possible), F:12.0h, E:49.5h, H:309W, L:800W
2024-06-02 05:32:20,438:INFO: INV: AC:288.6W, DC:303.8W (0.0|0.0|155.2|150.2), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:20,438:INFO: SMT: T:ShellyEM3 P:225.5W [ 45.5,45.5,51.1,61.1,87.0,128.4 ]
2024-06-02 05:32:20,438:INFO: Direct connected panel are producing 0.0W, trying to get 408.6W from hub.
2024-06-02 05:32:20,439:INFO: Turning hub bypass OFF
2024-06-02 05:32:20,439:INFO: Based on time, solarpower (172.4W) minimum charge power (0W) and bypass state (False), hub could contribute 408.6W - Decision path: 0.1.2.1.
2024-06-02 05:32:20,439:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:20,439:INFO: Solarflow is willing to contribute 204.0W (per channel) of the requested 408.6!
2024-06-02 05:32:20,439:INFO: Setting inverter output limit to 816W (1 min moving average of 204W x 4)
2024-06-02 05:32:20,439:INFO: Sun: 04:50 - 21:22 Demand: 408.6W, Panel DC: (0.0W), Hub DC: (290.2W), Inverter Limit: 816.0W, Hub Limit: 800.0W
2024-06-02 05:32:20,440:INFO: SMT triggers limit function: 87.0 -> 128.4: executed
2024-06-02 05:32:20,441:INFO: SMT triggers limit function: 89.6 -> 130.9: skipped
2024-06-02 05:32:20,443:INFO: SMT triggers limit function: 92.1 -> 133.3: skipped
2024-06-02 05:32:22,450:INFO: SMT triggers limit function: 100.9 -> 148.2: skipped
2024-06-02 05:32:22,451:INFO: SMT triggers limit function: 103.2 -> 150.1: skipped
2024-06-02 05:32:22,453:INFO: SMT triggers limit function: 103.6 -> 149.5: skipped
2024-06-02 05:32:22,816:INFO: SMT triggers limit function: 104.1 -> 149.0: skipped
2024-06-02 05:32:22,818:INFO: SMT triggers limit function: 104.6 -> 148.6: skipped
2024-06-02 05:32:22,820:INFO: SMT triggers limit function: 105.1 -> 148.2: skipped
2024-06-02 05:32:24,462:INFO: SMT triggers limit function: 112.2 -> 150.5: skipped
2024-06-02 05:32:24,464:INFO: SMT triggers limit function: 112.6 -> 150.1: skipped
2024-06-02 05:32:24,465:INFO: SMT triggers limit function: 113.0 -> 149.8: skipped
2024-06-02 05:32:26,475:INFO: SMT triggers limit function: 120.4 -> 150.7: skipped
2024-06-02 05:32:26,476:INFO: SMT triggers limit function: 120.7 -> 150.4: skipped
2024-06-02 05:32:26,478:INFO: SMT triggers limit function: 120.9 -> 149.9: skipped
2024-06-02 05:32:28,491:INFO: SMT triggers limit function: 128.5 -> 150.9: skipped
2024-06-02 05:32:28,493:INFO: SMT triggers limit function: 128.6 -> 150.4: skipped
2024-06-02 05:32:28,495:INFO: SMT triggers limit function: 128.7 -> 150.0: skipped
2024-06-02 05:32:29,818:INFO: SMT triggers limit function: 126.2 -> 145.7: skipped
2024-06-02 05:32:29,819:INFO: SMT triggers limit function: 123.7 -> 141.7: skipped
2024-06-02 05:32:29,821:INFO: SMT triggers limit function: 121.3 -> 137.9: skipped
2024-06-02 05:32:30,939:INFO: Triggering telemetry update: iot/A8yh63/ETFTke36/properties/read
2024-06-02 05:32:32,643:INFO: HUB: S:169.5W [ 173.5,173.5,173.0,171.3,170.8,169.5 ], B: 18% (18|18), V:48.5V (48.6|48.5), C:-208W, P:True (manual, not possible), F:12.0h, E:49.5h, H:366W, L:800W
2024-06-02 05:32:32,643:INFO: INV: AC:387.1W, DC:381.0W (0.0|0.0|222.4|215.0), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:32,643:INFO: SMT: T:ShellyEM3 P:-17.1W [ 61.2,61.2,70.8,93.9,121.2,117.5 ]
2024-06-02 05:32:32,643:INFO: Direct connected panel are producing 0.0W, trying to get 523.1W from hub.
2024-06-02 05:32:32,643:INFO: Turning hub bypass OFF
2024-06-02 05:32:32,643:INFO: Based on time, solarpower (169.5W) minimum charge power (0W) and bypass state (False), hub could contribute 523.1W - Decision path: 0.1.2.1.
2024-06-02 05:32:32,644:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:32,644:INFO: Solarflow is willing to contribute 261.5W (per channel) of the requested 523.1!
2024-06-02 05:32:32,644:INFO: Setting inverter output limit to 1044W (1 min moving average of 261W x 4)
2024-06-02 05:32:32,644:INFO: Sun: 04:50 - 21:22 Demand: 523.1W, Panel DC: (0.0W), Hub DC: (415.6W), Inverter Limit: 1044.0W, Hub Limit: 800.0W
2024-06-02 05:32:32,644:INFO: DTU triggers limit function: 351.2 -> 387.1: executed
2024-06-02 05:32:34,819:INFO: Rapid drop in demand detected, clearing buffer!
2024-06-02 05:32:34,819:INFO: HUB: S:167.0W [ 170.0,170.0,167.0 ], B: 18% (18|18), V:48.5V (48.6|48.5), C:-233W, P:False (manual, not possible), F:12.0h, E:49.5h, H:386W, L:800W
2024-06-02 05:32:34,819:INFO: INV: AC:387.1W, DC:407.4W (0.0|0.0|222.4|215.0), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:34,819:INFO: SMT: T:ShellyEM3 P:-134.4W [ -134.4,-134.4 ]
2024-06-02 05:32:34,819:INFO: Direct connected panel are producing 0.0W, trying to get 271.1W from hub.
2024-06-02 05:32:34,820:INFO: Based on time, solarpower (167.0W) minimum charge power (0W) and bypass state (False), hub could contribute 271.1W - Decision path: 2.1.
2024-06-02 05:32:34,820:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:34,820:INFO: Solarflow is willing to contribute 135.5W (per channel) of the requested 271.1!
2024-06-02 05:32:34,820:INFO: Setting inverter output limit to 540W (1 min moving average of 135W x 4)
2024-06-02 05:32:34,820:INFO: Grid feed in from battery: 144.4W!
2024-06-02 05:32:34,820:INFO: Sun: 04:50 - 21:22 Demand: 271.1W, Panel DC: (0.0W), Hub DC: (415.5W), Inverter Limit: 540.0W, Hub Limit: 800.0W
2024-06-02 05:32:34,820:INFO: SMT triggers limit function: -134.4 -> -134.4: executed
2024-06-02 05:32:35,533:INFO: DTU triggers limit function: 351.2 -> 387.1: skipped
2024-06-02 05:32:35,560:INFO: DTU triggers limit function: 351.2 -> 387.1: skipped
2024-06-02 05:32:35,585:INFO: DTU triggers limit function: 351.2 -> 387.1: skipped
2024-06-02 05:32:35,615:INFO: DTU triggers limit function: 351.2 -> 387.1: skipped
2024-06-02 05:32:35,640:INFO: DTU triggers limit function: 358.7 -> 392.4: skipped
2024-06-02 05:32:37,842:INFO: Rapid rise in demand detected, clearing buffer!
2024-06-02 05:32:37,842:INFO: HUB: S:167.0W [ 170.0,170.0,167.0 ], B: 18% (18|18), V:48.5V (48.6|48.5), C:-233W, P:True (manual, not possible), F:12.0h, E:49.5h, H:386W, L:800W
2024-06-02 05:32:37,843:INFO: INV: AC:392.4W, DC:413.0W (0.0|0.0|224.3|216.8), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:37,843:INFO: SMT: T:ShellyEM3 P:123.0W [ 123.0,123.0,123.0 ]
2024-06-02 05:32:37,843:INFO: Direct connected panel are producing 0.0W, trying to get 532.1W from hub.
2024-06-02 05:32:37,843:INFO: Turning hub bypass OFF
2024-06-02 05:32:37,843:INFO: Based on time, solarpower (167.0W) minimum charge power (0W) and bypass state (False), hub could contribute 532.1W - Decision path: 0.1.2.1.
2024-06-02 05:32:37,843:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:37,843:INFO: Solarflow is willing to contribute 266.0W (per channel) of the requested 532.1!
2024-06-02 05:32:37,843:INFO: Setting inverter output limit to 1064W (1 min moving average of 266W x 4)
2024-06-02 05:32:37,844:INFO: Sun: 04:50 - 21:22 Demand: 532.1W, Panel DC: (0.0W), Hub DC: (419.1W), Inverter Limit: 1064.0W, Hub Limit: 800.0W
2024-06-02 05:32:37,844:INFO: SMT triggers limit function: 123.0 -> 123.0: executed
2024-06-02 05:32:38,555:INFO: DTU triggers limit function: 358.7 -> 392.4: skipped
2024-06-02 05:32:38,558:INFO: DTU triggers limit function: 358.7 -> 392.4: skipped
2024-06-02 05:32:38,583:INFO: DTU triggers limit function: 358.7 -> 392.4: skipped
2024-06-02 05:32:38,607:INFO: DTU triggers limit function: 358.7 -> 392.4: skipped
2024-06-02 05:32:39,816:INFO: Rapid drop in demand detected, clearing buffer!
2024-06-02 05:32:39,816:INFO: HUB: S:167.0W [ 170.0,170.0,167.0 ], B: 18% (18|18), V:48.5V (48.6|48.5), C:-251W, P:True (manual, not possible), F:12.0h, E:49.5h, H:404W, L:800W
2024-06-02 05:32:39,816:INFO: INV: AC:400.8W, DC:421.9W (0.0|0.0|241.5|233.5), L:579W (144.8W/channel) [1600W]
2024-06-02 05:32:39,816:INFO: SMT: T:ShellyEM3 P:-140.6W [ -140.6,-140.6 ]
2024-06-02 05:32:39,816:INFO: Direct connected panel are producing 0.0W, trying to get 300.7W from hub.
2024-06-02 05:32:39,816:INFO: Turning hub bypass OFF
2024-06-02 05:32:39,817:INFO: Based on time, solarpower (167.0W) minimum charge power (0W) and bypass state (False), hub could contribute 300.7W - Decision path: 0.1.2.1.
2024-06-02 05:32:39,817:INFO: Not setting solarflow output limit to 800.0W as it is identical to current limit!
2024-06-02 05:32:39,817:INFO: Solarflow is willing to contribute 150.0W (per channel) of the requested 300.7!
2024-06-02 05:32:39,817:INFO: Setting inverter output limit to 600W (1 min moving average of 150W x 4)
2024-06-02 05:32:39,817:INFO: Grid feed in from battery: 150.6W!
2024-06-02 05:32:39,817:INFO: Sun: 04:50 - 21:22 Demand: 300.7W, Panel DC: (0.0W), Hub DC: (451.3W), Inverter Limit: 600.0W, Hub Limit: 800.0W
2024-06-02 05:32:39,817:INFO: SMT triggers limit function: -140.6 -> -140.6: executed

The paths are... strange... And my system decided at 7am, that BP is on and let full steam deplete the battery O.o

This behavior is new, as I was running a slightly older dev build before yesterday. But as I cannot switch the bp In ha as ha tells me this switch is not available anymore in mqtt, I tried a version update.

mavo commented 5 months ago

I fixed this by removing the changes in your last commit. This seems to be a problem, dunno why, but it is. I had It running the whole day with a small adjustment to not always drain 800w and instead only deliver what it required from the house, but I could see the weird paths all the time. It also mentioned a lot of times "turning BP off" in the logs.

Now, that I reverted to the older version of the BP check line it seems to be back to normal...

reinhard-brandstaedter commented 5 months ago

Which change exactly?

mavo commented 5 months ago

This one https://github.com/reinhard-brandstaedter/solarflow-control/commit/8fa4020866c78668c6686798f0f64d40f1532836

floriandrott commented 5 months ago

@reinhard-brandstaedter with the DEV version 4 days ago, it was two days ago working with the bypass switch. Maybe the reason was that solar power was very low this time and then the switch was working?

Today I switched to the latest DEV version and directly I saw that sf-control thinks BP mode is on but it isn't.

2024-06-04 16:47:30,374:INFO: Turning hub bypass OFF
2024-06-04 16:47:30,376:INFO: Reading last full time: 2024-06-02 19:43:06
2024-06-04 16:47:30,376:INFO: Reading battery target mode: discharging
2024-06-04 16:47:30,376:INFO: Set ChargeThrough: False
2024-06-04 16:47:30,376:INFO: Solarflow set DryRun: False
2024-06-04 16:47:30,376:INFO: OpenDTU set DryRun: False
2024-06-04 16:47:30,376:INFO: Reading last empty time: 2024-05-18 08:38:41
2024-06-04 16:47:30,419:INFO: Solarflow set DryRun: False
2024-06-04 16:47:30,419:INFO: OpenDTU set DryRun: False
2024-06-04 16:47:48,102:INFO: Determined inverter's max capacity: 800.0
2024-06-04 16:49:30,374:INFO: HUB: S:833.5W [ 833.0,833.0,833.3,833.5 ], B: 95% (95), V:51.1V (51.1), C: 601W, P:True (manual, possible), F:45.1h, E:416.2h, H:199W, L:600W
2024-06-04 16:49:30,374:INFO: INV: AC:204.8W, DC:216.2W (108.1|108.1), L:202W (100.8W/channel) [800W]
2024-06-04 16:49:30,374:INFO: SMT: T:Smartmeter P:43.0W [ 44.6,44.6,44.9,43.2,42.1,42.0 ]
2024-06-04 16:49:30,374:INFO: Direct connected panel are producing 0.0W, trying to get 206.8W from hub.
2024-06-04 16:49:30,375:INFO: Based on time, solarpower (833.5W) minimum charge power (250W) and bypass state (True), hub could contribute 600.0W - Decision path: 0.2.

reinhard-brandstaedter / solarflow-control

Bypass state not recognized correctly on Hub2000 #244