Repository: home-assistant/core
Pull request: Change SimpliSafe websocket reconnection log to `DEBUG`-level
<!--
  You are amazing! Thanks for contributing to our project!
  Please, DO NOT DELETE ANY TEXT from this template! (unless instructed).
-->
## Proposed change
<!--
  Describe the big picture of your changes here to communicate to the
  maintainers why we should accept this pull request. If it fixes a bug
  or resolves a feature request, be sure to link to that issue in the
  additional information section.
-->
SSIA

## Type of change
<!--
  What type of change does your PR introduce to Home Assistant?
  NOTE: Please, check only 1! box!
  If your PR requires multiple boxes to be checked, you'll most likely need to
  split it into multiple PRs. This makes things easier and faster to code review.
-->

- [ ] Dependency upgrade
- [x] Bugfix (non-breaking change which fixes an issue)
- [ ] New integration (thank you!)
- [ ] New feature (which adds functionality to an existing integration)
- [ ] Deprecation (breaking change to happen in the future)
- [ ] Breaking change (fix/feature causing existing functionality to break)
- [ ] Code quality improvements to existing code or addition of tests

## Additional information
<!--
  Details are important, and help maintainers processing your PR.
  Please be sure to fill out additional details, if applicable.
-->

- This PR fixes or closes issue: fixes https://github.com/home-assistant/core/issues/129506
- This PR is related to issue: N/A
- Link to documentation pull request: N/A

## Checklist
<!--
  Put an `x` in the boxes that apply. You can also fill these out after
  creating the PR. If you're unsure about any of them, don't hesitate to ask.
  We're here to help! This is simply a reminder of what we are going to look
  for before merging your code.
-->

- [x] The code change is tested and works locally.
- [x] Local tests pass. **Your PR cannot be merged unless tests pass**
- [x] There is no commented out code in this PR.
- [x] I have followed the [development checklist][dev-checklist]
- [x] I have followed the [perfect PR recommendations][perfect-pr]
- [x] The code has been formatted using Ruff (`ruff format homeassistant tests`)
- [ ] Tests have been added to verify that the new code works.

If user exposed functionality or configuration variables are added/changed:

- [ ] Documentation added/updated for [www.home-assistant.io][docs-repository]

If the code communicates with devices, web services, or third-party tools:

- [ ] The [manifest file][manifest-docs] has all fields filled out correctly.  
      Updated and included derived files by running: `python3 -m script.hassfest`.
- [ ] New or updated dependencies have been added to `requirements_all.txt`.  
      Updated by running `python3 -m script.gen_requirements_all`.
- [ ] For the updated dependencies - a link to the changelog, or at minimum a diff between library versions is added to the PR description.

<!--
  This project is very active and we have a high turnover of pull requests.

  Unfortunately, the number of incoming pull requests is higher than what our
  reviewers can review and merge so there is a long backlog of pull requests
  waiting for review. You can help here!
  
  By reviewing another pull request, you will help raise the code quality of
  that pull request and the final review will be faster. This way the general
  pace of pull request reviews will go up and your wait time will go down.
  
  When picking a pull request to review, try to choose one that hasn't yet
  been reviewed.

  Thanks for helping out!
-->

To help with the load of incoming pull requests:

- [ ] I have reviewed two other [open pull requests][prs] in this repository.

[prs]: https://github.com/home-assistant/core/pulls?q=is%3Aopen+is%3Apr+-author%3A%40me+-draft%3Atrue+-label%3Awaiting-for-upstream+sort%3Acreated-desc+review%3Anone+-status%3Afailure

<!--
  Thank you for contributing <3

  Below, some useful links you could explore:
-->
[dev-checklist]: https://developers.home-assistant.io/docs/development_checklist/
[manifest-docs]: https://developers.home-assistant.io/docs/creating_integration_manifest/
[quality-scale]: https://developers.home-assistant.io/docs/integration_quality_scale_index/
[docs-repository]: https://github.com/home-assistant/home-assistant.io
[perfect-pr]: https://developers.home-assistant.io/docs/review-process/#creating-the-perfect-pr


Problem statement:
SimpliSafe - Reconnecting to websocket
### The problem

Receiving the below warning in the Core logs - is this a known issue or is there a fix?

Logger: homeassistant.components.simplisafe
Source: components/simplisafe/__init__.py:488
integration: SimpliSafe (documentation, issues)
First occurred: October 15, 2024 at 8:54:35 AM (29596 occurrences)
Last logged: 10:53:25 AM

Reconnecting to websocket

### What version of Home Assistant Core has the issue?

core-2024.10.1

### What was the last working version of Home Assistant Core?

unknown

### What type of installation are you running?

Home Assistant OS

### Integration causing the issue

SimpliSafe

### Link to integration documentation on our website

_No response_

### Diagnostics information

_No response_

### Example YAML snippet

_No response_

### Anything in the logs that might be useful for us?

_No response_

### Additional information

_No response_

Hints from issue discussion:
Hey there @bachya, mind taking a look at this issue as it has been labeled with an integration (`simplisafe`) you are listed as a [code owner](https://github.com/home-assistant/core/blob/dev/CODEOWNERS#L1336) for? Thanks!

<details>
<summary>Code owner commands</summary>


Code owners of `simplisafe` can trigger bot actions by commenting:

- `@home-assistant close` Closes the issue.
- `@home-assistant rename Awesome new title` Renames the issue.
- `@home-assistant reopen` Reopen the issue.
- `@home-assistant unassign simplisafe` Removes the current integration label and assignees on the issue, add the integration domain after the command.
- `@home-assistant add-label needs-more-information` Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
- `@home-assistant remove-label needs-more-information` Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

</details>


<sub><sup>(message by CodeOwnersMention)</sup></sub>

---

[simplisafe documentation](https://www.home-assistant.io/integrations/simplisafe)
[simplisafe source](https://github.com/home-assistant/core/tree/dev/homeassistant/components/simplisafe)
<sub><sup>(message by IssueLinks)</sup></sub>
That's merely a log message. Are you experiencing an issue?
I have received this message in my logs as well. Both an Error and a Warning. (screenshot was taken ≅5 minutes after the timestamp shown)

![Screenshot From 2024-11-05 13-16-32](https://github.com/user-attachments/assets/0b2e73c9-cf45-445d-8a72-7010b5834dcb)

Also, saying "that's merely a log message" is dismissive. IMO, there should be no Errors or Warnings in my logs--certainly not hundreds. I'm a simple sysadmin, but to me "errors" are Bad™; "warnings" are Almost Bad™. They are indications of breakage, not something to be dismissed.
I see thousands of these warnings as well. I don't think this is normal behavior
I see over 1000 of these messages in less than 24 hours. 
Though my integration is working, I am also getting these errors…don’t think should be happening if everything is working fine.
If this is "fine" consider if the log level of `WARNING` should be reduced, perhaps?
I've been away (my day job and a new baby have taken my open-source dev time down to 0%), and I appreciate everyone's patience.

Several items are going on here; please allow me to address them individually.

First, to the several comments about the sheer volume of messages (and the corresponding "annoyance factor"), I can't control this. As has been well documented (both by me and others), we rely on a regularly flaky, unpublished SimpliSafe cloud API for this integration. As such, I've had to reverse-engineer every interaction, including the connection to this websocket. It often drops for no particular reason; because essential messages come from it, I forcefully reconnect to it at every opportunity to maintain the experience for my downstream users.

Second, I disagree with several comments about these messages being at the incorrect level. One comment above states:

> IMO, there should be no Errors or Warnings in my logs--certainly not hundreds. I'm a simple sysadmin, but to me "errors" are Bad™; "warnings" are Almost Bad™.

If it were up to me, we wouldn't be dealing with a flaky upstream API. As I've already shared, that isn't the case. Furthermore, there are instances where a websocket reconnection indicates something other than flakiness (i.e., a real error condition that I don't know about and which should be addressed in code). In that case, it's important for the log message to exist—how else would I troubleshoot later on?

Put differently: these are warning-level logs because they might _be_ warnings. SimpliSafe's API isn't reliable, so I'm left to do my best with what I have. I ultimately want the integration to work well for our users; everything else is icing on the cake.

If the volume of log messages is unnerving for some, they can always reduce the SimpliSafe logs to only output error level or above (knowing they can always return to the original level if debugging warrants it).

Lastly, we have to take other non-HASS users into account. The library that records these logs (`simplisafe-python`) is used by many different projects; it wouldn't be appropriate to assume that they wouldn't want websocket disconnections/forceful reconnections to be logged.

I hope this gives everyone some insight into the complexity of this situation. I'm open to continuing the discussion!
I appreciate that you're engaging with us more now. Absolutely, though, Life™ comes first.

I also appreciate the situation you're in. I'm not trying to imply that there's a perfect solution here. But maybe we can work together to create something a bit better than where we are today? That's all I'm trying to get to--understanding and betterment.

For example,

> there are instances where a websocket reconnection indicates something other than flakiness (i.e., a real error condition that I don't know about and which should be addressed in code). In that case, it's important for the log message to exist—how else would I troubleshoot later on?
> Put differently: these are warning-level logs because they might be warnings.

100% agree. But the next question is, how do I know which is which? Because you dismissed our concern about the log messages without seeing any of them. Is there something you know that makes for an **actionable** "WARNING ... Reconnecting to websocket" log message? 

You're saying that you include straw in the logs bc there might be needles. My point is, with the volume of straw, how can I as a user or you as a developer find the needles in that haystack?

I understand the difficulty of reverse engineering black box functionality. And I totally understand that, sometimes, you need to reconnect to a service every 5 minutes (as shown in some of my logs). And I understand that, sometimes for one of those reconnects, you need to retry a connection to a service 58 times in 13.435 seconds before you make a valid connection (as shown in my logs).

But is there some way--any way--to differentiate that kind of straw from the needles? Even if you err on the side of logging some false positives, is there some way to reduce the amount? Or highlight known bad messages?

I'm not sure how Python logging libraries work, but I know that it is sometimes possible in logging systems and libraries to set a threshold for specific log messages or log message types. Is it possible for **reconnects only** to alert individually for <6 messages in under 30 seconds AND roll up more than that into one message? That way we'd still see the 5-minute reconnect, but the occasional 58-message reconnect would be just one message. Something like "WARNING ... Reconnecting to websocket (58 attempts)"

And, finally, if this kind of thing is to be expected, maybe it's worth including a sentence or two about it in [the Integration docs](https://www.home-assistant.io/integrations/simplisafe/)? Something like "Due to a lack of documentation by Simplisafe, the integration may log reconnection events frequently (as often as every 5 minutes) and burst reconnections up to 100 times. As long as your blah blah is okay, you can safely ignore these messages."

----

I am engaging about all of this from my own comfort level as a sysadmin, but I have to assume that the majority of my perspective in this matter is aligned with that of less technical users. IMO, trying to reduce the number of log messages is in the category of being a good citizen in the HA ecosystem. For example, out of the 10,000 line log download I just performed going back 6.5 days, 8,990 lines are this message. If I wanted to find a problem that's NOT SimpliSafe, it might rotate out or be impossible to find in the HA interface. 

I have log servers and log analysis/filter tools available to me; I know how to reach out to a dev on GitHub and engage in a technical manner; I know that when I see something with a 5m1s  periodicity and no functionality degradation, it's *probably* not bad.

But what about Pat Novice who's having problems with their first HA automation to turn the lights off when they set their Simplisafe to away? They may follow random advice to go to the logs, see this, and maybe spend hours reinstalling, reconfiguring, and resetting the HA Integration and their Simplisafe itself, when they might have just made a simple mistake with the automation trigger?
All good feedback, @KlfJoat. And now that I dug a little here, I have to apologize: I assumed this issue was about a log message coming from `simplisafe-python,` but the reconnection message is something I put into the HASS integration. After reviewing that (specifically, looking for your point about finding a needle), I see your point. There's little value in logging that event (which inherently has no additional info) beyond a DEBUG-level log (I could see wanting to know if reconnections are happening in rapid order, but can instruct someone to go to DEBUG-level logs if that happens).

So, the previous suggestion to turn this into a DEBUG-level event seems appropriate. That will ensure that only genuine websocket errors (which can still happen with SS's flaky API) are logged during "normal" business.

Thanks, all, for your patience—new dad brain raced over the initial point without validating it well enough!

Commit message: Change SimpliSafe websocket reconnection log to `DEBUG`-level

Patch to review:
diff --git a/homeassistant/components/simplisafe/__init__.py b/homeassistant/components/simplisafe/__init__.py
index b72519f973480..df434e0a775cc 100644
--- a/homeassistant/components/simplisafe/__init__.py
+++ b/homeassistant/components/simplisafe/__init__.py
@@ -248,7 +248,7 @@ def _async_register_base_station(
 
     # Check for an old system ID format and remove it:
     if old_base_station := device_registry.async_get_device(
-        identifiers={(DOMAIN, system.system_id)}  # type: ignore[arg-type]
+        identifiers={(DOMAIN, system.system_id)}
     ):
         # Update the new base station with any properties the user might have configured
         # on the old base station:
@@ -485,7 +485,7 @@ async def _async_start_websocket_loop(self) -> None:
         except Exception as err:  # noqa: BLE001
             LOGGER.error("Unknown exception while connecting to websocket: %s", err)
 
-        LOGGER.warning("Reconnecting to websocket")
+        LOGGER.debug("Reconnecting to websocket")
         await self._async_cancel_websocket_loop()
         self._websocket_reconnect_task = self._hass.async_create_task(
             self._async_start_websocket_loop()


Code review comments:
diff_hunk: @@ -248,7 +248,7 @@ def _async_register_base_station(
 
     # Check for an old system ID format and remove it:
     if old_base_station := device_registry.async_get_device(
-        identifiers={(DOMAIN, system.system_id)}  # type: ignore[arg-type]
path: homeassistant/components/simplisafe/__init__.py
text: @author:
Including this to satisfy `pre-commit`.

@user1:
I am interested in why this was here, because it would probably not have worked as we're creating devices with a str and querying them with a number

@author:
That strict typing wasn't always required; guessing it's a very old relic.

@user1:
But I mean more like, is this code still relevant? Because this query would not fetch any new devices, so this didn't work for the last while

@user1:
I think we can remove this migration now, it was added 2 years ago

@author:
Actually, I see what's going on: this typing is "newer" (compared to when this was originally implemented), and this logic was in place to ensure that a string was used.