search

springfall2008 / batpred

Home battery prediction and charging automation for Home Assistant, supporting many inverter types
https://springfall2008.github.io/batpred/
113 stars 39 forks source link

Solis failed to update charge/discharge times #1294

Open marcoaddario opened 1 month ago

marcoaddario commented 1 month ago

Describe the bug My setup has 2 modbus clients for the inverter. one is the original solis datalogger and another one is homeassistant. In this setup the bus is available only to a client a time.

In some situation (e.g. when the inverter modbus is busy uploading data to the solis website) the button.push action times out due to a too much aggressive timing. It happened few times in pas weeks (solis site more busier than usual???) that predbad fails to save the charge or discharge time and on the successive run do not retries because the HA params are already set by the previous run. As workaround I have increased the write_and_poll_sleep params in config.py to 4 seconds and it seems ok, but I think that the charge /discharge times in HA should be restored to the previous state if the button.press service do not complete successfully. In this way predbat should try again on the next run.

Expected behavior in case of unsuccessful inverter charge/discharge time set all the params should be restored to the previous state and the write_and_poll_sleep can be increased a little bit more to face specific bus vulnerabilities.

Predbat version

8.2.4 (but is not s behavior specific to this version)

Environment details

Log file

2024-07-08 23:30:20.182826 INFO pred_bat: Inverter 0 set new start time to 00:00:00                                                                                                                                                                                                                                                   
2024-07-08 23:30:24.234441 INFO pred_bat: Inverter 0 Wrote 00:00:00 to discharge_start_time, successfully now 00:00:00                                                                                                                                                                                                                
2024-07-08 23:30:28.274043 INFO pred_bat: Inverter 0 Wrote 0 to discharge_start_hour, successfully now 0                                                                                                                                                                                                                              
2024-07-08 23:30:32.306195 INFO pred_bat: Inverter 0 Wrote 0 to discharge_start_minute, successfully now 0                                                                                                                                                                                                                            
2024-07-08 23:30:32.307780 INFO pred_bat: Inverter 0 Set new end time to 00:00:00 was 23:31:00                                                                                                                                                                                                                                        
2024-07-08 23:30:36.346442 INFO pred_bat: Inverter 0 Wrote 00:00:00 to discharge_end_time, successfully now 00:00:00                                                                                                                                                                                                                  
2024-07-08 23:30:40.393290 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_hour, successfully now 0                                                                                                                                                                                                                                
2024-07-08 23:30:44.444276 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_minute, successfully now 0                                                                                                                                                                                                                              
2024-07-08 23:31:09.090833 INFO pred_bat: Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete                                                                                                                                                                                          
2024-07-08 23:31:09.110243 INFO pred_bat: Info: record_status Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete                                                                                                                                                                      
2024-07-08 23:31:09.111745 INFO pred_bat: Inverter 0 Current charge limit is 86 % and new target is 100 %                                                                                                                                                                                                                             
2024-07-08 23:31:13.146405 INFO pred_bat: Inverter 0 Wrote 100 to charge_limit, successfully now 100                                                                                                                                                                                                                                  
2024-07-08 23:31:13.151537 INFO pred_bat: Solis Energy Control Switch setting 35 Self-Use unchanged for charge True
springfall2008 commented 1 month ago

I've increased the polling times on main, see if it helps if not I can try the other option

marcoaddario commented 1 month ago

I can still see some issues. I am wondering if the problem may be the way predbat get the button status to see if the event has been triggered. I have checked the timings and even if predabt claims that the time between the button status and the current time is greater than 10s (as far as I understood, this is how it checks if the events has been fired) it is not:

These are logs and specific timing for a situation that just happened:

this is the predbat log

2024-07-17 17:30:15.943677 INFO pred_bat: Inverter 0 Wrote 00:00:00 to discharge_end_time, successfully now 00:00:00                                                                                                                                                                                                                  
2024-07-17 17:30:19.990204 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_hour, successfully now 0                                                                                                                                                                                                                                
2024-07-17 17:30:24.036039 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_minute, successfully now 0                                                                                                                                                                                                                              
2024-07-17 17:30:57.033607 INFO pred_bat: Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete                                                                                                                                                                                          
2024-07-17 17:30:57.074077 INFO pred_bat: Info: record_status Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete                                                                                                                                                                      
2024-07-17 17:30:57.081655 INFO pred_bat: Solis Energy Control Switch setting 35 Self-Use unchanged for eco True                                                                                                                                                                                                                      
2024-07-17 17:30:57.157851 INFO pred_bat: Will not recompute the plan, it is 5.0 minutes old and max age is 10 minutes

but the button status changed every 4 seconds (the time you set as timeout)

image

the strange thing is that is not always happening :-(

happy to make any test or further investigation you may need

marcoaddario commented 1 month ago

another thing I have noticed is that the charge and discharge times are sometimes overlapping, but this is not allowed by Solis. both the webapp and the cloud site have controls to prevent it before submitting it:

2024-07-19 14:15:12.264066 INFO pred_bat: Found 1 inverters totals: min reserve 0.28 current reserve 0.28 soc_max 7.1 soc 7.1 charge rate 3.5999999999999996 kW discharge rate 3.5999999999999996 kW battery_rate_min 100.0 w ac limit 4.6 export limit 4.6 kW loss charge 3 % loss discharge 3 % inverter loss 4 %
2024-07-19 14:15:12.330415 INFO pred_bat: Base charge    window [ 19-07 23:30:00 - 20-07 05:30:00 @ 0p 87%, 20-07 23:30:00 - 21-07 05:30:00 @ 0p 87% ] 
2024-07-19 14:15:12.331553 INFO pred_bat: Base discharge window [ 19-07 00:00:00 - 19-07 15:31:00 @ 0p 0.0%, 20-07 00:00:00 - 20-07 15:31:00 @ 0p 0.0% ]
2024-07-19 14:15:12.332487 INFO pred_bat: Charge window will be: 2024-07-19 23:30:00+01:00 - 2024-07-20 05:30:00+01:00 - current soc 100 target 100
2024-07-19 14:15:12.333630 INFO pred_bat: Not setting charging window yet as not within the window (now 07-19 14:15:00 target set_window_minutes 30 charge start time 07-19 23:30:00)
2024-07-19 14:15:12.334883 INFO pred_bat: Next discharge window will be: 2024-07-19 14:20:00+01:00 - 2024-07-19 15:31:00+01:00 at reserve 88
2024-07-19 14:15:16.359657 INFO pred_bat: Inverter 0 Wrote Eco to inverter_mode, successfully now Eco
2024-07-19 14:15:16.361186 INFO pred_bat: Inverter 0 set force discharge to False
2024-07-19 14:15:20.401254 INFO pred_bat: Switch sensor.predbat_GS_0_scheduled_discharge_enable is now off
2024-07-19 14:15:20.406364 INFO pred_bat: Inverter 0 Wrote scheduled_discharge_enable to False successfully and got off
2024-07-19 14:15:20.410730 INFO pred_bat: Inverter 0 Turning off scheduled discharge 
2024-07-19 14:15:20.415154 INFO pred_bat: Inverter 0 Adjust force discharge to False, change times from 00:00:00 - 15:31:00 to 00:00:00 - 00:00:00
2024-07-19 14:15:20.419793 INFO pred_bat: Adjust idle time, charge 23:30:00-05:30:00 discharge 00:00:00-00:00:00
2024-07-19 14:15:20.424912 INFO pred_bat: Adjust idle time computed idle is 14:15:00-23:30:00
2024-07-19 14:15:20.430461 INFO pred_bat: Inverter 0 Set new end time to 00:00:00 was 15:31:00

2024-07-19 14:15:24.487102 INFO pred_bat: Inverter 0 Wrote 00:00:00 to discharge_end_time, successfully now 00:00:00
2024-07-19 14:15:28.528276 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_hour, successfully now 0
2024-07-19 14:15:32.592889 INFO pred_bat: Inverter 0 Wrote 0 to discharge_end_minute, successfully now 0
2024-07-19 14:16:05.677399 INFO pred_bat: Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete 
2024-07-19 14:16:05.728972 INFO pred_bat: Info: record_status Warn: Inverter 0 Trying to press button.solis_modbus_update_charge_discharge_times didn't complete
2024-07-19 14:16:05.734433 INFO pred_bat: Solis Energy Control Switch setting 35 Self-Use unchanged for eco True                                                                                                                                                                                                                      2024-07-19 14:16:05.922303 INFO pred_bat: Completed run status Idle
2024-07-19 14:16:06.300465 INFO pred_bat: Info: record_status Idle 
2024-07-19 14:16:06.344492 INFO pred_bat: Saved current settings to /config/predbat_config.json
marcoaddario commented 1 month ago

this is going to be fixed by https://github.com/springfall2008/batpred/pull/1324

springfall2008 commented 3 weeks ago

Currently on 'main' I believe