[ISSUE] setting charge limit can cause an automation to hang for 5 minutes
nicois opened this issue · 4 comments
Home Assistant Version
2024.12.2
MG/SAIC Integration Version
0.8.1
Installation Method
Manual
Did you check for existing issues?
- Yes, I have checked for existing issues
- No, I have not checked for existing issues
Did you enable debug logging before and are ready to post logs?
- Yes, I have enabled debug logging
- No, I have not enabled debug logging
Describe the Issue
When trying to use an automation to enable charging AND set a charge limit, the step takes about 5 minutes to complete. I do not always see this delay; it might be more evident when there has been other recent SAIC-related activity.
I will attach logs after I open this issue. I'll include a small extract now, showing how partway through an automation nothing continues, as it's waiting for 5 minutes before receiving a reply to the previous communication, without forcing a resync sooner.
Logs
Dec 30 21:49:55 orangepi3-lts hass[1066784]: 2024-12-30 21:49:55.245 DEBUG (MainThread) [custom_components.mg_saic] Vehicle Charging Data: ChrgMgmtDataResp(chrgMgmtData=ChrgMgmtData(bmsAdpPubChrgSttnDspCmd=0, bmsAltngChrgCrntDspCmd=4, bmsChrgCtrlDspCmd=1, bmsChrgOtptCrntReq=108, bmsChrgOtptCrntReqV=0, bmsChrgSpRsn=0, bmsChrgSts=1, bmsDsChrgSpRsn=0, bmsEstdElecRng=369, bmsOnBdChrgTrgtSOCDspCmd=5, bmsPackCrnt=19913, bmsPackCrntV=0, bmsPackSOCDsp=745, bmsPackVol=1633, bmsPTCHeatReqDspCmd=2, bmsPTCHeatResp=0, bmsPTCHeatSpRsn=None, bmsReserCtrlDspCmd=2, bmsReserSpHourDspCmd=6, bmsReserSpMintueDspCmd=0, bmsReserStHourDspCmd=22, bmsReserStMintueDspCmd=0, ccuEleccLckCtrlDspCmd=1, ccuOffBdChrgrPlugOn=0, ccuOnbdChrgrPlugOn=3, chrgngAddedElecRng=0, chrgngAddedElecRngV=0, chrgngDoorOpenCnd=0, chrgngDoorPosSts=1, chrgngRmnngTime=127, chrgngRmnngTimeV=0, chrgngSpdngTime=0, chrgngSpdngTimeV=0, clstrElecRngToEPT=338, disChrgngRmnngTime=1023, disChrgngRmnngTimeV=1, imcuChrgngEstdElecRng=366, imcuChrgngEstdElecRngV=0, imcuDschrgngEstdElecRng=221, imcuDschrgngEstdElecRngV=0, imcuVehElecRng=338, imcuVehElecRngV=0, onBdChrgrAltrCrntInptCrnt=45, onBdChrgrAltrCrntInptVol=116), rvsChargeStatus=RvsChargeStatus(chargingDuration=30, chargingElectricityPhase=None, chargingGunState=1, chargingPileID=None, chargingPileSupplier=None, chargingType=6, endTime=0, extendedData1=None, extendedData2=None, extendedData3=None, extendedData4=None, fotaLowestVoltage=None, fuelRangeElec=3380, lastChargeEndingPower=None, mileage=9750, mileageOfDay=40, mileageSinceLastCharge=0, powerUsageOfDay=9, powerUsageSinceLastCharge=0, realtimePower=540, startTime=1735555762, staticEnergyConsumption=None, totalBatteryCapacity=725, workingCurrent=19913, workingVoltage=1633))
Dec 30 21:49:55 orangepi3-lts hass[1066784]: 2024-12-30 21:49:55.246 DEBUG (MainThread) [custom_components.mg_saic] State updated: Is Powered On: False, Is Charging: True, Last Powered On Time: 2024-12-29 10:42:11.013495+00:00, Last Powered Off Time: 2024-12-29 10:42:11.013478+00:00, Last Vehicle Activity: 2024-12-30 10:42:31.993879+00:00, Update Interval: 0:05:00
Dec 30 21:49:55 orangepi3-lts hass[1066784]: 2024-12-30 21:49:55.246 DEBUG (MainThread) [custom_components.mg_saic] Finished fetching MG SAIC data update coordinator data in 6.815 seconds (success: True)
Dec 30 21:49:55 orangepi3-lts hass[1066784]: 2024-12-30 21:49:55.246 DEBUG (MainThread) [custom_components.mg_saic] Next update scheduled in 0:05:00.
Dec 30 21:49:55 orangepi3-lts hass[1066784]: 2024-12-30 21:49:55.251 DEBUG (MainThread) [custom_components.mg_saic] Sensor Interior Temperature has invalid temperature value -128
Dec 30 21:53:17 orangepi3-lts hass[1066784]: 2024-12-30 21:53:17.632 WARNING (MainThread) [homeassistant.components.automation.vac_ev_plug_on_when_excess_production] EV start charging when excess production : Already running
Dec 30 21:54:55 orangepi3-lts hass[1066784]: 2024-12-30 21:54:55.257 DEBUG (MainThread) [custom_components.mg_saic] Evaluating interval adjustment: Powered On: False, Charging: True, Idle Duration: 1 day, 0:12:44.244175, Activity Duration: 0:12:23.263774
Dec 30 21:54:55 orangepi3-lts hass[1066784]: 2024-12-30 21:54:55.258 DEBUG (MainThread) [custom_components.mg_saic] Vehicle is charging. Using charging update interval.
Dec 30 21:54:55 orangepi3-lts hass[1066784]: 2024-12-30 21:54:55.258 DEBUG (MainThread) [custom_components.mg_saic] Adjusted update interval: 0:10:00.
Dec 30 21:54:55 orangepi3-lts hass[1066784]: 2024-12-30 21:54:55.258 DEBUG (MainThread) [custom_components.mg_saic] Next update scheduled in 0:10:00.
Additional Context
The key part of the automation is this, I believe. The turn_on
command is executed at December 30, 2024 at 9:49:07 PM
but then the set_value
is delayed until December 30, 2024 at 9:54:55 PM
sequence:
- type: turn_on
device_id: 78d6a3ec26654df82a072fe714baae37
entity_id: b4fa1617ae1e25664b40c92cc07c7fa0
domain: switch
- action: input_number.set_value
metadata: {}
data:
value: -500
target:
entity_id: input_number.ev_next_step_up
- delay:
hours: 0
minutes: 0
seconds: 30
milliseconds: 0
- device_id: 78d6a3ec26654df82a072fe714baae37
domain: select
entity_id: a246613caa3d8b60b33a44655346d12e
type: select_option
option: 6A
I've attached a trace of the automation which experienced the 5 minute delay, along with the journal logs from this interval.
trace automation.vac_ev_plug_on_when_excess_production 2024-12-30T10_49_07.668659+00_00.json
start_charging-trace.log
Hi @nicois
Not really sure if I got a clear idea of the issue.
Can you elaborate on the input numbers and the device id's and entity id's that appear on the automation code?
I will try to have a look, but I'm not sure what might be the cause. Did you try to manually execute those steps with the available services?
Cheers
The basic problem is that when I try to set the charge limit in an automation, there is often an additional 5 limit delay. For example, here you can see the automation started at 4:40
and finished at 4:45
:
Despite the final step running a 4:40
, it takes 5 minutes before the step completes, which in this case ends the automation:
My guess is this is a side-effect of using two separate selectors and sensors to track what the underlying SAIC/MG API treats as arguments to the same endpoint. I think there is logic in the retry backoff which doesn't realise that changing only the charging limit needs to supersede the existing delay.
In a little more detail: when the target SOC is set, you schedule follow-up polls of the car's state, as the async processing takes a variable number of seconds to take effect. So you poll in a few seconds ,then backoff and try again, and eventually schedule a retry after 5 minutes. But when the charge limit selector is modified, this 5 minute delay somehow blocks the selector from re-polling, confirming the change had taken effect, and completing the action. This leads to needing to wait the full 5 minutes for the already-scheduled poll event to take place.
Ok. I believe I got it now.
The thing is that the every action as a short interval update period and each action as a long interval update period. Whenever there's an action triggered, to avoid collisions with other updates, I set a flag to only respond to the actions' update intervals and not others.
Then. In the case of "Charging Current Limit", the default interval is 5 minutes.
Maybe try to set this to a lower period on your case (e.g. 2 minutes) and see if it fixes the issue for you.
Cheers