Repository navigation
Solis: don't let a refused startup register read abort startup, and back off B0600 #5185
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -364,15 +364,27 @@ def compute_solis_mode_value(mode_enum, old_value, drop_tou_bit=False): | |
| "10404": "Not found", | ||
| "10500": "Internal server error", | ||
| "B0115": "Datalogger offline or disconnected", | ||
| "B0600": "Datalogger returns data abnormally", | ||
| "R0000": "Daily API request allowance exhausted", | ||
| } | ||
|
|
||
| # Response codes that are settled for this cycle: retrying cannot change the answer, and every | ||
| # attempt still spends one of the 200 daily requests. B0115 means the datalogger is offline, not | ||
| # that the request was throttled, and R0000 means the daily allowance is already gone (issue #5087). | ||
| # B0600 came back on every remote read and every retry, across days, on the account in issue #5177, | ||
| # from a datalogger the owner could see online in SolisCloud. | ||
| SOLIS_API_CODE_QUOTA_EXCEEDED = "R0000" | ||
| SOLIS_API_CODE_DATALOGGER_OFFLINE = "B0115" | ||
| SOLIS_API_CODES_NO_RETRY = {SOLIS_API_CODE_QUOTA_EXCEEDED, SOLIS_API_CODE_DATALOGGER_OFFLINE} | ||
| SOLIS_API_CODE_DATALOGGER_ABNORMAL = "B0600" | ||
| SOLIS_API_CODES_NO_RETRY = {SOLIS_API_CODE_QUOTA_EXCEEDED, SOLIS_API_CODE_DATALOGGER_OFFLINE, SOLIS_API_CODE_DATALOGGER_ABNORMAL} | ||
|
|
||
| # Codes that put one inverter into the datalogger cooldown, and how the log and run status describe | ||
| # each. Both back off the same way; B0600 just must not be reported as offline, because the owner can | ||
| # see the datalogger online in SolisCloud (issue #5177). | ||
| SOLIS_DATALOGGER_COOLDOWN_REASONS = { | ||
| SOLIS_API_CODE_DATALOGGER_OFFLINE: "offline or disconnected", | ||
| SOLIS_API_CODE_DATALOGGER_ABNORMAL: "returning data abnormally (B0600)", | ||
| } | ||
|
|
||
| # Time options for selectors (HH:MM:SS format) | ||
| BASE_TIME = datetime(2000, 1, 1, 0, 0, 0) | ||
|
|
@@ -455,6 +467,7 @@ def initialize(self, api_key=None, api_secret=None, inverter_sn=None, automatic= | |
| self.slots_reset = set() # Track which inverters had slots reset | ||
| self.quota_exhausted_until = None # UTC time the daily API allowance pause lifts, None when not paused | ||
| self.datalogger_offline_until = {} # {inverter_sn: UTC time that inverter's reads resume} | ||
| self.datalogger_cooldown_code = {} # {inverter_sn: API code of its latest datalogger refusal} | ||
| self.automatic_config_done = False # Auto-config succeeded, so it does not need re-running | ||
| self.capacity_voltage_warned = set() # Inverters already warned about an estimated capacity voltage | ||
| self.verify_settle_seconds = SOLIS_VERIFY_SETTLE_SECONDS # Pause before a verify read is re-taken, 0 in tests | ||
|
|
@@ -564,36 +577,67 @@ def note_quota_restored(self): | |
| self.log("Solis API: SolisCloud daily API request allowance has been restored, resuming normal polling") | ||
|
|
||
| def datalogger_offline(self, inverter_sn): | ||
| """Whether this inverter's datalogger is in its offline cooldown and should not be polled""" | ||
| """Whether this inverter's datalogger is in its cooldown (B0115 or B0600) and should not be polled""" | ||
| offline_until = self.datalogger_offline_until.get(inverter_sn) | ||
| return bool(offline_until) and self.now_utc_exact.astimezone(UTC) < offline_until | ||
|
|
||
| def note_datalogger_offline(self, inverter_sn): | ||
| """Back off this inverter's reads after SolisCloud reports its datalogger is offline. | ||
| def note_datalogger_offline(self, inverter_sn, code): | ||
| """Back off this inverter's reads after SolisCloud refuses them with a datalogger code. | ||
|
|
||
| Not retrying a B0115 is only half the cure: run() polls every inverter every minute, so an | ||
| offline datalogger left in the rotation still spends a request a minute out of the 200 a day | ||
| and is how the account in issue #5087 reached R0000 in the first place. | ||
| and is how the account in issue #5087 reached R0000 in the first place. A B0600 is backed | ||
| off the same way, but code keeps it from being reported as offline (issue #5177). | ||
| """ | ||
| if not inverter_sn or self.datalogger_offline(inverter_sn): | ||
| if not inverter_sn: | ||
| return | ||
| # Always the latest refusal, so the run status follows a B0115 that turns into a B0600 | ||
| self.datalogger_cooldown_code[inverter_sn] = code | ||
| if self.datalogger_offline(inverter_sn): | ||
| # Already backed off - don't extend the cooldown or re-log on each refused read | ||
| return | ||
| resume_at = self.now_utc_exact.astimezone(UTC) + timedelta(seconds=SOLIS_DATALOGGER_OFFLINE_SECONDS) | ||
| self.datalogger_offline_until[inverter_sn] = resume_at | ||
| self.log("Warn: Solis API: Datalogger for inverter {} is offline or disconnected, pausing its reads until {}".format(inverter_sn, resume_at.strftime("%H:%M:%S UTC"))) | ||
| self.log("Warn: Solis API: Datalogger for inverter {} is {}, pausing its reads until {}".format(inverter_sn, self.datalogger_cooldown_reason(inverter_sn), resume_at.strftime("%H:%M:%S UTC"))) | ||
|
|
||
| def datalogger_cooldown_reason(self, inverter_sn): | ||
| """How the log and run status describe this inverter's latest datalogger refusal""" | ||
| code = self.datalogger_cooldown_code.get(inverter_sn, SOLIS_API_CODE_DATALOGGER_OFFLINE) | ||
| return SOLIS_DATALOGGER_COOLDOWN_REASONS.get(code, code) | ||
|
|
||
| def note_datalogger_online(self, inverter_sn): | ||
| """Clear an inverter's offline cooldown after one of its reads succeeds""" | ||
| """Clear an inverter's datalogger cooldown after one of its reads succeeds""" | ||
| if inverter_sn and self.datalogger_offline_until.pop(inverter_sn, None): | ||
| self.log("Solis API: Datalogger for inverter {} is back online".format(inverter_sn)) | ||
| self.datalogger_cooldown_code.pop(inverter_sn, None) | ||
| self.log("Solis API: Datalogger for inverter {} is answering requests again".format(inverter_sn)) | ||
|
|
||
| def forget_expired_datalogger_cooldown(self, inverter_sn): | ||
| """Drop an expired cooldown once a request for its inverter fails for a reason that is not a datalogger refusal. | ||
|
|
||
| The run status keeps a datalogger reason past its cooldown until a request succeeds, but once a | ||
| re-probe fails for something else - an HTTP error, a timeout, R0000 - the datalogger is no | ||
| longer the latest explanation, and reporting it would hide e.g. a SolisCloud outage. | ||
| """ | ||
| if inverter_sn and inverter_sn in self.datalogger_offline_until and not self.datalogger_offline(inverter_sn): | ||
| self.datalogger_offline_until.pop(inverter_sn, None) | ||
| self.datalogger_cooldown_code.pop(inverter_sn, None) | ||
|
|
||
| def health_message(self): | ||
| """Name the reason Solis is unhealthy so the run status says more than 'component errors: Solis'""" | ||
| if self.quota_exhausted_until: | ||
| return "Solis Cloud daily API limit reached, paused until {}".format(self.quota_exhausted_until.strftime("%H:%M UTC")) | ||
| offline = sorted(sn for sn in self.datalogger_offline_until if self.datalogger_offline(sn)) | ||
| if offline: | ||
| return "datalogger offline for inverter {}".format(", ".join(offline)) | ||
| # Every inverter still carrying a cooldown entry, expired or not: like the quota diagnostic it is | ||
| # cleared by a request that succeeds, not by the cooldown expiring (or, once it has, by a re-probe | ||
| # that fails for some other reason). A component stuck in startup backoff re-probes up to | ||
| # two hours apart, far longer than the cooldown, so tying this to the cooldown would leave the run | ||
| # status blank for most of that time (issue #5177). | ||
| # Only inverters still being polled, since no request will ever clear one that has left the | ||
| # rotation (dropped by discovery or by the inverter_sn setting). | ||
| by_reason = {} | ||
| for sn in sorted(sn for sn in self.datalogger_offline_until if sn in self.inverter_sn): | ||
| by_reason.setdefault(self.datalogger_cooldown_reason(sn), []).append(sn) | ||
| if by_reason: | ||
| return "; ".join("datalogger {} for inverter {}".format(reason, ", ".join(sns)) for reason, sns in by_reason.items()) | ||
| return None | ||
|
|
||
| async def _execute_request(self, endpoint, payload): | ||
|
|
@@ -602,7 +646,7 @@ async def _execute_request(self, endpoint, payload): | |
| # are refused but still counted, so sending them is what keeps it exhausted (issue #5087). | ||
| if self.quota_paused(): | ||
| raise SolisAPIError("SolisCloud daily API request allowance exhausted, requests paused until {}".format(self.quota_exhausted_until.strftime("%Y-%m-%d %H:%M:%S UTC")), response_code=SOLIS_API_CODE_QUOTA_EXCEEDED) | ||
| # Which inverter this request is for, so a B0115 backs off that one rather than the fleet. | ||
| # Which inverter this request is for, so a datalogger refusal (B0115, B0600) backs off that one rather than the fleet. | ||
| # The read/control endpoints name it "inverterSn", the detail endpoint "sn"; the account-wide | ||
| # inverter list names neither, and has no single inverter to blame. | ||
| request_inverter_sn = payload.get("inverterSn") or payload.get("sn") | ||
|
|
@@ -635,6 +679,7 @@ async def _execute_request(self, endpoint, payload): | |
| await self.handle_oauth_401() | ||
| reason = "auth_error" if response.status in (401, 403) else "server_error" | ||
| record_api_call("solis", False, reason) | ||
| self.forget_expired_datalogger_cooldown(request_inverter_sn) | ||
| raise SolisAPIError(f"HTTP error: {error_text}", status_code=response.status) | ||
|
|
||
| # Parse JSON response | ||
|
|
@@ -648,12 +693,14 @@ async def _execute_request(self, endpoint, payload): | |
| error_msg = response_json.get("msg", "Unknown error") | ||
| error_detail = SOLIS_API_CODES.get(str(code), f"Unknown code: {code}") | ||
| record_api_call("solis", False, "server_error") | ||
| if str(code) == SOLIS_API_CODE_QUOTA_EXCEEDED: | ||
| self.note_quota_exhausted() | ||
| elif str(code) == SOLIS_API_CODE_DATALOGGER_OFFLINE: | ||
| if str(code) in SOLIS_DATALOGGER_COOLDOWN_REASONS: | ||
| # Not throttling, whatever the old 10 second sleep assumed: the datalogger | ||
| # is offline, so this inverter is backed off rather than retried. | ||
| self.note_datalogger_offline(request_inverter_sn) | ||
| # won't answer, so this inverter is backed off rather than retried. | ||
| self.note_datalogger_offline(request_inverter_sn, str(code)) | ||
| else: | ||
| self.forget_expired_datalogger_cooldown(request_inverter_sn) | ||
| if str(code) == SOLIS_API_CODE_QUOTA_EXCEEDED: | ||
| self.note_quota_exhausted() | ||
| raise SolisAPIError(f"API error: {error_msg} ({error_detail} - {response_json})", response_code=str(code)) | ||
|
|
||
| # Return data field | ||
|
|
@@ -664,9 +711,11 @@ async def _execute_request(self, endpoint, payload): | |
|
|
||
| except asyncio.TimeoutError as err: | ||
| record_api_call("solis", False, "connection_error") | ||
| self.forget_expired_datalogger_cooldown(request_inverter_sn) | ||
| raise SolisAPIError(f"Timeout accessing {url}") from err | ||
| except aiohttp.ClientError as err: | ||
| record_api_call("solis", False, "connection_error") | ||
| self.forget_expired_datalogger_cooldown(request_inverter_sn) | ||
| raise SolisAPIError(f"Network error accessing {url}: {str(err)}") from err | ||
|
|
||
| async def _with_retry(self, operation, max_retry_time=SOLIS_MAX_RETRY_TIME): | ||
|
|
@@ -683,8 +732,9 @@ async def _with_retry(self, operation, max_retry_time=SOLIS_MAX_RETRY_TIME): | |
| # burning the full retry window hitting the API with a known-bad token. | ||
| if self.oauth_failed: | ||
| raise err | ||
| # An exhausted allowance or an offline datalogger will answer every retry the same | ||
| # way, and each attempt still costs one of the 200 daily requests (issue #5087). | ||
| # An exhausted allowance, or a datalogger that is offline (B0115) or refusing reads | ||
| # (B0600), will answer every retry the same way, and each attempt still costs one of | ||
| # the 200 daily requests (issues #5087, #5177). | ||
| if err.response_code in SOLIS_API_CODES_NO_RETRY: | ||
| raise err | ||
| elapsed_time = time.monotonic() - start_time | ||
|
|
@@ -3555,15 +3605,33 @@ async def run(self, seconds, first): | |
|
|
||
| # Get inverter details for all inverters | ||
| for sn in self.inverter_sn: | ||
| # An inverter whose datalogger is in its cooldown is left to the first startup attempt after the | ||
| # cooldown expires: early backoff re-runs this block every 2-8 minutes, well inside the cooldown, | ||
| # and every request sent here would be refused yet still count against the 200 a day (issue #5177). | ||
| # Failing the poll keeps the component in startup, so that later attempt does come. | ||
| if self.datalogger_offline(sn): | ||
| poll_success = False | ||
| continue | ||
| await self.fetch_inverter_details(sn) | ||
| await self.poll_inverter_data(sn, [SOLIS_CID_TOU_V2_MODE]) # Get TOU V2 mode status | ||
| if not self.datalogger_offline(sn): | ||
| await self.poll_inverter_data(sn, [SOLIS_CID_TOU_V2_MODE]) # Get TOU V2 mode status | ||
| if self.datalogger_offline(sn): | ||
| # Refused on this attempt, so its TOU mode and startup reset wait for the next one | ||
| poll_success = False | ||
| continue | ||
| if self.is_tou_v2_mode(sn): | ||
| self.log(f"Solis API: Inverter {sn} is in Time of Use V2 mode") | ||
| else: | ||
| self.log(f"Solis API: Inverter {sn} is in standard Time of Use mode") | ||
| if self.control_enable: | ||
| if self.is_battery_inverter(sn): | ||
| await self.startup_reset_registers(sn) # Reset registers on startup to ensure we have write access and correct initial state | ||
| # Best effort: it only lowers one setting. Left to raise, a datalogger that refuses the | ||
| # read (B0600, B0115) aborted every startup attempt, so the inverter was never | ||
| # configured at all (issue #5177). | ||
| try: | ||
| await self.startup_reset_registers(sn) # Reset registers on startup to ensure we have write access and correct initial state | ||
| except Exception as e: | ||
| self.log(f"Warn: Solis API: Startup register reset failed for inverter {sn}, continuing without it: {e}") | ||
|
Owner
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. The try/except only ever catches the initial read: read_and_write_cid() swallows its own failures and returns False, which startup_reset_registers() (line 3524) ignores. A refused/failed write still leaves the over-discharge SoC above the 20% default with only read_and_write_cid's generic 'Failed to read and set ...' warn — this 'Startup register reset failed' warning and the issue-#5177 framing never fire for the write half, so the survivable step is only observable on its read half.
Owner
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. 🤖 Automated reply from the triage bot. Not changed, because the write half cannot run today.
Fixing the unpacking would switch on a write that has never happened in production: lowering every inverter's over-discharge SoC to 20% at each startup. That is a behaviour change for a maintainer to decide, not a review fix, so I've kept it out of this PR. If it is wanted, the unpacking fix and a write-failure warning belong together in a follow-up. |
||
| else: | ||
| # automatic_config() logs its own version of this, but only when auto-config is on | ||
| self.log(f"Solis API: Inverter {sn} reports no battery attached, so Predbat will poll it but not write any control registers to it") | ||
|
|
||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The guard makes the reset best-effort, but the whole startup block above (fetch_inverter_details, the TOU-v2 poll, this reset read — the
for snloop at line 3580) never checksdatalogger_offline(sn). During startup backoff each re-probe still sends up to 3 requests to a datalogger its own cooldown says not to poll: the 2/4/8-minute early backoff gaps all fall inside the 15-minute cooldown, so those attempts each spend ~3 refused requests out of the 200/day allowance (the budget pressure issue #5087 was about). The new run-path test asserts 'exactly one request is sent' only because fetch_inverter_details/poll_inverter_data are mocked — production sends ~4 per attempt. Gating the first block's per-inverter calls ondatalogger_offline(sn)(they still fire once the cooldown expires, so re-probing is unaffected) would make production match the test's claim.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🤖 Automated reply from the triage bot.
Fixed in 2d51c66. The first-cycle loop now skips an inverter whose datalogger is in its cooldown. It also re-checks after the detail read and after the TOU mode read, so it stops at the first refusal that starts a cooldown. A skipped inverter sets
poll_success = False, which keeps the component in startup, so the first attempt after the cooldown expires re-probes it.The new
test_startup_leaves_an_inverter_in_datalogger_cooldown_alonedrives the real detail, poll and reset code against a session that answers B0600 to everything:Against the previous commit, the first attempt sent 3.