Skip to content
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

Log output flooded with Home Connect API error: Service Temporarily Unavailable #34

Closed
DJay-X opened this issue Oct 21, 2020 · 3 comments
Labels
enhancement New feature or request

Comments

@DJay-X
Copy link

DJay-X commented Oct 21, 2020

Hi @thoukydides first I hope you are well these days.

As also to see in your status server page, the HC Service API was down again vor a couple of hours.
Is there any chance to reduce the output in the log not showing every second the error? The log is flooded with this message over and over at the moment running continuously.

Thanks in advance for your consideration.

Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:20 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:20] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:21 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:21] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:22 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:22] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:22 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:22] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:22 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:22] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Okt 21 17:49:22 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:22] [HomeConnect] Starting events stream for all appliances
Okt 21 17:49:22 raspberrypi-3BPlus homebridge[8484]: [2020-10-21 17:49:22] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
@DJay-X DJay-X added the enhancement New feature or request label Oct 21, 2020
@thoukydides
Copy link
Owner

It's a tricky one...

Due to the API rate limits it is necessary to rely entirely on the event stream... so when the event stream is terminated there is a window where events may be lost and the state of the appliances can start to differ from what the plugin has cached. Hence, it is best to try and re-establish the event stream as quickly as possible to minimise potential issues. I therefore don't want to introduce any delays before trying to reconnect (other than where unavoidable due to the rate limits).

It is also an aspect of the API that has shown quite a few problems previously, some of them very intermittent and hard to reproduce. For this reason I am also reluctant to reduce the amount of information that is logged. Without logs of each connection attempt and its outcome I wouldn't have been able to diagnose and workaround some of the previous failure mechanisms.

I could possibly add a delay before retrying for this one specific error message. It probably won't ever be triggered again after today's outage, so that doesn't really seem worth it.

The only other idea I currently have is to implement a new log filtering mechanism, between the raw log messages and the Homebridge log facility. This would need to keep a history of recent log entries, identify duplicates of recent entries, and have rules for how frequently duplicates should be written to the log. However, it would take a reasonable amount of effort to do something worthwhile, and the danger is that it would make routine logs more difficult to analyse and interpret. Again, for something that is probably a one-off event it doesn't seem worth the effort.

@thoukydides
Copy link
Owner

Checking my own server's log it looks more like this (because I run with debug enabled for my own plugins):

Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Starting events stream for all appliances
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Home Connect request #61992: STREAM https://api.home-connect.com/api/homeappliances/events
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Oven] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Induction Hob] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Dishwasher] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Home Connect request #61992: Service Temporarily Unavailable +102ms
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Oven] Event STOP (0 items)
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Induction Hob] Event STOP (0 items)
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Dishwasher] Event STOP (0 items)
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Starting events stream for all appliances
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Home Connect request #61993: STREAM https://api.home-connect.com/api/homeappliances/events
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Oven] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Induction Hob] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Dishwasher] Events may have been missed; treating appliance as disconnected
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Home Connect request #61993: Service Temporarily Unavailable +105ms
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] Terminated events stream for all appliances: Home Connect API error: Service Temporarily Unavailable
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Oven] Event STOP (0 items)
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Induction Hob] Event STOP (0 items)
Oct 21 17:00:34 i7pc homebridge[30342]: [10/21/2020, 17:00:34] [HomeConnect] [Dishwasher] Event STOP (0 items)

For log message filtering to be useful in this case it wouldn't just need to check for an exact match in recent log messages, but it would need to be some form of fuzzy match due to the inclusion of the API request numbers and timings. Even less worth the effort...

@thoukydides
Copy link
Owner

It looks like the API has been fine for the last hour.

Unless outages with this failure mode become a regular issue I am not going to do anything to reduce logging, so am closing this issue for now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

2 participants