Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
112 changes: 90 additions & 22 deletions apps/predbat/solis.py
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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):
Expand All @@ -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")
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand All @@ -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):
Expand All @@ -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
Expand Down Expand Up @@ -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

Copy link
Copy Markdown
Owner Author

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 sn loop at line 3580) never checks datalogger_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 on datalogger_offline(sn) (they still fire once the cooldown expires, so re-probing is unaffected) would make production match the test's claim.

Copy link
Copy Markdown
Owner Author

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_alone drives the real detail, poll and reset code against a session that answers B0600 to everything:

  • the first attempt sends 1 request;
  • the attempts at 2, 6 and 14 minutes send none;
  • the attempt at 30 minutes re-probes with 1.

Against the previous commit, the first attempt sent 3.

except Exception as e:
self.log(f"Warn: Solis API: Startup register reset failed for inverter {sn}, continuing without it: {e}")

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

The 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.

Copy link
Copy Markdown
Owner Author

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.

Not changed, because the write half cannot run today.

startup_reset_registers() does value = await self.read_cid(...), but read_cid() returns a (value, info) tuple. It has done so since #3654, a week before this function arrived in 9f43e43 and c52ae1d. float() of that tuple raises TypeError, the except sets value = 0, and the > 20 write never executes. So there is no refused write to report, and a warning there would be dead code.

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")
Expand Down
Loading
Loading