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

A Single Appliance (Thermador Oven) Reaches Blocked Status #460

Closed
PrestonMcAfee opened this issue Dec 22, 2024 · 31 comments
Closed

A Single Appliance (Thermador Oven) Reaches Blocked Status #460

PrestonMcAfee opened this issue Dec 22, 2024 · 31 comments

Comments

@PrestonMcAfee
Copy link

PrestonMcAfee commented Dec 22, 2024

Describe the bug

I have two appliances, Thermador oven and dishwasher. I was frequently rate-limited. Following instructions, I separated these two devices with distinct credentials. The dishwasher is now never rate-limited, but cooking will lead to BLOCKED for the oven. If the oven is not turned on, no block arises. So far this has always taken 24 hours to resolve on its own. I created a third set of credentials and can change the oven to them if I need the oven reporting.

When its working, the temperature does seem to update frequently, e.g. every sixty seconds or even more often, but that should still take over 10 hours to hit 1000 API calls. I'd be happy to update less frequently but do not see a setting that lets me do so.

Specific questions: Do the number of entities matter or are API calls at the appliance level? is there a way to limit API calls per appliance to, say, every five minutes?

Version of the custom_component

1.1.12

Configuration

I have two always-on tablets that among other things show the oven temperature. Moreover these reload their dashboards every 15 minutes (otherwise the time on the dashboard stops updating). If that update creates an API call, it could cause the overage, because 100 times per day X 28 entities could result in 2800 API calls if each entity is called separately. I tried disabling most of the entities -- I only use current program and cavity temperature -- without effect. Dashboard reloads should not be the cause because rate limiting only happens when cooking, not when the oven is off, and the dashboard reloads happen either way.

Debug log

I'm attaching two logs, one recorded during the block period (earlier) and one recorded after I changed credentials so that the oven was unblocked, in case they might be helpful.
home-assistant_home_connect_alt_2024-12-22T17-12-32.040Z.log
home-assistant_home_connect_alt_2024-12-22T18-32-54.373Z.log

@ekutner
Copy link
Owner

ekutner commented Dec 23, 2024

All of you calculations are wrong because none of those things would trigger a API call. Calls are triggered only when you change some settings, like starting, stopping or selecting a different program, just reading values doesn't trigger a call.
Neither of the two attached logs indicates a API rate limit, what makes you think that you are getting blocked?
Also, it seems that you have two accounts connected with the same appliances so you are getting non-unique IDs. You shouldn't do that and if you only have one appliance you should probably stick to a single account.

@PrestonMcAfee
Copy link
Author

I'm sorry I was unclear.

I have two appliances - dishwasher and oven -- and started using separate dev accounts so that when the oven was blocked, the dishwasher continued to work. I thought I was hitting the API rate limit because I saw the word BLOCKED in the device settings. I created a third set of credentials so that when the oven integration stopped working (e.g. sensor.thermador_prg486wdh_68a40e2c6663_340_bsh_common_status_operationstate became unavailable) I could switch to the other integration and make it work. This is what I did to create the second log.

I do see in the logs that the oven cavity temperature was available even when the operationstate was not. So I will trigger the BLOCKED state again so that I can send a screenshot of what I am seeing as well as the log. And if I can't trigger, I will report that too.

@ekutner
Copy link
Owner

ekutner commented Dec 23, 2024

ok, before getting the log file please also press the "Home Connect Debug Info" button for every config entry you have (there should be one for every account you added).
As for using two entries for the same device, that is creating duplicate IDs and shouldn't be done. An appliance can only be active under a single config entry (== a single Client ID)

@PrestonMcAfee
Copy link
Author

I ran the oven for six hours and did not trigger the BLOCKED state. I will write again if I reproduce the problem, with Home Connect Debug Info pressed. You can close this and happy holidays.

I am seeing things that look like API calls, but only to the oven, none to the dishwasher. 240 entries that look like:
2024-12-22 10:32:28.130 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/commands (try=1 count=14)
I attach the last half of the log file. I pressed the Home Connect Debug Info buttons several times. I have three accounts total but with two appliances, when one goes down I remove its account and add the other, so there are only two accounts at any given time, and I use code like
thermador_dwhd650wfp_68a40e0b2c4c: disabled: true
to ensure that each account only handles one appliance. I know this code works because when the oven is BLOCKED, I still see the status of the dishwasher.

home-assistant_home_connect_alt_2024-12-23T20-14-58.352Z.log

@PrestonMcAfee
Copy link
Author

It happened again. I am attaching three documents: two screenshots showing BLOCKED
Screenshot from 2024-12-28 12-10-56
Screenshot from 2024-12-28 12-11-23
and the log file for the past 36 hours, which has this in it:

2024-12-28 12:13:45.784 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances (try=1 count=4) [429]
2024-12-28 12:13:45.784 DEBUG (MainThread) [home_connect_async.api] HTTP Error 429 - Too Many Requests. Sleeping for 76803 seconds and will retry
2024-12-28 12:13:45.871 DEBUG (MainThread) [home_connect_async.api] HTTP GET /api/homeappliances/THERMADOR-DWHD650WFP-68A40E0B2C4C/commands (try=1 count=34) [200]

home-assistant_home_connect_alt_2024-12-28T20-14-04.365Z.log

but I don't know if that excerpt is evidence about the problem. Reminder: I have two thermador appliances, a dishwasher (thermador_dwhd650wfp_68a40e0b2c4c) and an oven (thermador_prg486wdh_68a40e2c6663_340). I use two Home Connect Alt credentials, one for the dishwasher with code:

thermador_prg486wdh_68a40e2c6663_340:
  disabled: true

Let me know if there is more information I can provide and thanks in advance.

and the other for the oven with code:

thermador_dwhd650wfp_68a40e0b2c4c:
  disabled: true

Right at this moment I am receiving data from the dishwasher but not the oven.

@ekutner
Copy link
Owner

ekutner commented Dec 29, 2024

The HTTP 429 status is indeed an indication that the client was rate limited, however, I need the entire log file, and possibly the previous one as well, to see how it got to that state. I see that this is relatively a new log, in the sense that it is shortly after restarting HA and the calls are already blocked, so it must have gotten to that state earlier, probably before the restart. Bottom line is that from this part of the log I can't tell which excessive calls caused your account to get blocked. Next time this happens please attach the full log with at least a full day of history.

@PrestonMcAfee
Copy link
Author

PrestonMcAfee commented Dec 29, 2024

Okay, I truncated the log because it would not fit in the 25MB limit. I thought I got the relevant time. However it was probably not recording at the time the problem happened. The available full log is here. But I don't expect that to help.

Home_Connect_Alt has recovered, so I am restarting HA and then I will trigger logging and leave it logging. Once the problem recurs, I will post the full log, and if it is too large, I will use the above method of posting a link in my tmp folder. Please let me know if something else would be more useful.

I appreciate your contribution -- I like having the oven temperature on my dashboard so that I know when the oven is left on, and a defect in the thermador dishwasher is that it is almost impossible to tell from the appliance itself if you have set it for delay or not, but easy from my dashboard -- and I especially appreciate your patience in sorting out what I'm doing wrong, given my inexperience with HA and the underlying tech.

@ekutner
Copy link
Owner

ekutner commented Dec 29, 2024

The link doesn't work. In general it is very unusual for a single appliance to trigger a rate limit, in fact I don't think I've ever seen it happening before. To understand what is causing it I need a log with enough history before getting blocked that would show the excessive calls that triggered it, assuming there really were such calls. The call counter should show the progress from a low number to a much higher one (the limit is 1000 calls a day) in the 24h window.

@PrestonMcAfee
Copy link
Author

Trying again. Sorry about that. I lost the TLD when I pasted. I also edited the comment. This is what I have back to Dec 22 until I noticed but I didn't have logging enabled the whole time. I have logging on now and will leave it on until the problem recurs. It typically requires a significant use of the oven to trigger the rate limit, so it may be some time. I only see ~60 API calls in the logs, so am unclear why I am triggering the rate limit.

@override80
Copy link

It might be related to this, but I'm having a similar problem, i get BLOCKED after a few hours. Looking at the debug logs, it seems that it's doing a lot of requests:

https://www.swisstransfer.com/d/899dbb10-7a8b-42ca-8c96-93fc1cfe9142

@ekutner
Copy link
Owner

ekutner commented Jan 1, 2025

@override80
There are a lot of calls because your appliance is getting disconnected and reconnected to the HC cloud. Every time it is connected again a full refresh of the data is done, generating a lot of calls. You should check your wifi and intenet connection.
Even with all these calls there is no indication of rate limit in the log.

@override80
Copy link

Yes, unfortunately the connection is very unstable, @ekutner ... Is there anything i can do to make it better from the integration perspective?

@ekutner
Copy link
Owner

ekutner commented Jan 1, 2025

@override80 I'm afraid not

@override80
Copy link

@override80 I'm afraid not

Ok thank you!

@PrestonMcAfee
Copy link
Author

An unstable web connection should not be the source of my API calls -- I have a wired ubiquiti AP with line of sight to the oven, about 6m away with a managed mesh. Additionally, the problem has arisen only when the oven is on.

Rereading the instructions, I had not set up logging level 7 but now have and have logging on, so hopefully I will capture the 24 hours leading up to the next rate limit correctly.

@PrestonMcAfee
Copy link
Author

Okay, it happened again. There are 2K HTTP GET in the past 24 hours, and the device

thermador_prg486wdh_68a40e2c6663_340

went offline. I attach the logs. Let me know what I am doing wrong and if I somehow botched the logging, I will try again.
home-assistant_home_connect_alt_2025-01-04T23-45-29.431Z.log

Many of the errors say "There is no program selected".

@PrestonMcAfee
Copy link
Author

PrestonMcAfee commented Jan 8, 2025

What I am seeing in the logs is 1908 instances of
HTTP GET /api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected
but that double-counts, because there is one instance for the request, and one for the response, many of which are [404 Not Found] about twice per second, or [429 Too Many Requests] when 50 requests in a minute occur. Some of them end in [200 OK] and then give information on program, heating, etc.

The last successful example of these requests occurs at line 34497, though other successes (e.g. programs/available) occur subsequently. The next attempt to get programs/selected, at 34609, results in[404 Not Found] and SDK.Error.NoProgramSelected, at which point the HTTP GET requests are fired off several times per second until a 429 timeout/rate limit is hit and a 15 second penalty imposed. After 25 instances of hitting the 429 rate limit, the 24 hour rate limit is imposed.

Now there are some instances in the data where a 404 is followed with a fraction of second by a 200 success.

Overall I would be happy to live with waiting 90 seconds after a 404 before trying another API call. With that I would never be rate limited.

There is another kind of HTTP GET in the log:
HTTP GET /api/homeappliances
which I think might be coming from my pushing of the debug info button.

@ekutner
Copy link
Owner

ekutner commented Jan 14, 2025

This is caused by a bug in Home Connect (not the integration). You can see it here:

2025-01-04 13:46:41.940 DEBUG (MainThread) [home_connect_async.homeconnect] Received event from SSE stream: MessageEvent(type='NOTIFY', message='NOTIFY', data='{"haId":"THERMADOR-PRG486WDH-68A40E2C6663-340","items":[{"handling":"none","key":"BSH.Common.Option.ElapsedProgramTime","level":"hint","name":"Program running time","timestamp":1736027056,"unit":"seconds","uri":"/api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected/BSH.Common.Option.ElapsedProgramTime","value":838}]}', origin='https://api.home-connect.com', last_event_id='THERMADOR-PRG486WDH-68A40E2C6663-340')
2025-01-04 13:46:41.940 DEBUG (MainThread) [home_connect_async.appliance] Got event for unknown property: {'handling': 'none', 'key': 'BSH.Common.Option.ElapsedProgramTime', 'level': 'hint', 'name': 'Program running time', 'timestamp': 1736027056, 'unit': 'seconds', 'uri': '/api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected/BSH.Common.Option.ElapsedProgramTime', 'value': 838}
2025-01-04 13:46:41.940 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected (try=1 count=978)

2025-01-04 13:46:42.165 DEBUG (MainThread) [home_connect_async.api] 
HTTP GET /api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected (try=1 count=978) [404 Not Found] ====>
{
  "error": {
    "description": "There is no program selected",
    "key": "SDK.Error.NoProgramSelected"
  }
}

The HC server is sending an event for a change in an option with this URI, which indicates it is an option for the selected program: /api/homeappliances/THERMADOR-PRG486WDH-68A40E2C6663-340/programs/selected/BSH.Common.Option.ElapsedProgramTime

Since the integration doesn't currently have a record for the selected program it tries to get it but gets an error that there is program selected (which is why it doesn't have a record of such a program in the first place). Since these notifications are received every second (and not every 60 seconds as usual) and since the integration just tries to get the selected program every time, it quickly gets rate limited.

If this issue is still happening for you, which means HC haven't fixed it yet, I can try to implement a workaround but for that I need the internal state of the integration while the these events are coming through, which means while the oven is cooking and the progress events are being received. The state is dumped to the log when you press the "Home Connect debug info" button. In your case you would have multiple such buttons, one for every config entry you created. So I need you to press all of these buttons (or just the one for the config entry associated with the over, if you know which one it is).
BTW, I see in the log that you did press this button, but you pressed the wrong instance, because the over is disabled in that one. The easiest way to ensure you got the right one is to just press all of them.

@PrestonMcAfee
Copy link
Author

home-assistant_home_connect_alt_2025-01-15T16-56-59.330Z.log

I see two Home Connect Service Home Connect Debug Info buttons, along with two Home Connect Service Home Connect Refresh buttons. I pressed all four of these multiple times because I can't see which goes to which appliance. On my phone the names are cut off, though I could avoid the refresh buttons because they always come after the debug buttons.

There is also one Home Connect Debug Info and one Home Connect Refresh button, grayed out.

Hopefully the attached log provides what you need. The service goes into temporary blockage very quickly so I pushed all the buttons, turned on the oven, pushed all the buttons, and soon after went into the short time BLOCKED state, and pushed all the buttons again.

Thank you.

@ekutner
Copy link
Owner

ekutner commented Jan 15, 2025

Try version 1.2.0-b1
If it doesn't solve the problem then please upload a fresh log.
Do not press the "Home Connect Refresh" button because it just reloads all the data from HC, which a) makes a lot of calls and b) soils the log and makes it harder to see what's actually happening.

There is also one Home Connect Debug Info and one Home Connect Refresh button, grayed out.

This probably belongs to a config entry that was removed, you have to manually delete it.

@PrestonMcAfee
Copy link
Author

Thank you. I'm running 1.2.0-b1 now, but was BLOCKED and it appears to be the 24 hour kind, so it will be tomorrow at the earliest before I know if this is working and really I probably need to cook a few times to know.

I no longer see the unavailable Home Connect Debug Info and Home Connect Refresh buttons. Deleting them had not eliminated them even with a restart, but perhaps they needed a redownload to vanish.

@smacphee85
Copy link

I’ve been tracking this through this thread and another for a while as I have been experiencing the same issues as @PrestonMcAfee. I just loaded 1.2.0-b1 and for the first time ever was able to heat my Thermador oven AND watch it cool without my account being BLOCKed within moments of the oven starting. So from my perspective, initial results are positive and appreciated!

@PrestonMcAfee is the final authority, but if I can provide any insights please ask.

@PrestonMcAfee
Copy link
Author

@smacphee85: yay! I hope I have the same experience.

@bakoscsaba
Copy link

I have the same issue as described. I have a Bosch Serie 6 oven and a dishwasher. I got blocked after a couple of hours.
Now I have installed 1.2.0-b1 as suggested and also separated the config so the oven and dishwasher uses separate developer accounts.
Now the dishwasher connection is stable but the oven gets banned for 24 hours even on 1.2.0-b1.

@PrestonMcAfee
Copy link
Author

@bakoscsaba 1.2.0-b1 seems to be working for me -- I just ran the oven and got none of the failed 'program selected' errors that spawned API calls in the logs.

When the BLOCKED is released (probably 24 hours), enable logging level 7 (Settings / Integrations / Home Connect Alt / Configure / Verbose Logging, slider all the way to the right) and then enable debug logging (Settings/Integrations/Home Connect Alt). Turn on the oven, go to overview and then to your appliance (You can search Home Connect to find) and Press the Debug Info button(s). That logs the state.

Once BLOCKED comes back, stop logging (same button that enabled), and either the log is automatically saved or you get the option to save the log file, I think depending on your browser settings. In the file, look for HTTP GET in the logs -- these are API calls. If you are getting them because of a no program selected error, that is what is fixed.

Note that others (different threads) triggered too many API calls because of poor WIFI connections and that should also be visible in the log file if the oven was disconnected. That isn't a problem with Home Connect Alt and isn't fixed by this update.

@bakoscsaba
Copy link

Hi,

I managed to collect logs last night. To me it seems there are lot of 'no program selected' error in the logs, but I really can't tell what is the root cause of my issue.
I started recording the logs in the evening and let the oven and dishwasher run for a couple of hours. Tried to change some setting then left them turned off for the night and in the morning the connection was blocked. Log recording was stopped in the morning.
I attach here what I have. I would appreciate if you could have a look and advice what could be the problem.
Actually the appliances are approx. 3 meters away from my rooter so I would be surprised if it is due to bad connection.

home-assistant_home_connect_alt_2025-01-20T06-13-04.577Z.log

@PrestonMcAfee
Copy link
Author

Probably we have to wait for ekutner to take a look. I have little knowledge.

You do have many duplicate appliance notices. That can arise from having two distinct sets of credentials but not partitioning the appliances across credentials. Did you lose access to the dishwasher when the oven went out? On the Overview Dashboard, you should see two Home Connect Status entries, one BLOCKED and one READY.

To partition the items you need something like

bosch_hrg5785s6_68a40ebaae38_001
disabled: true

under advanced appliance settings (YAML) for one of the credentials, and a similar statement for the other, which looks to be 014090542064001178, though that should be a longer name which is itself curious.

I would try to fix the unique ID conflicts to see if that resolves the problem.

@bakoscsaba
Copy link

You are right, both Home Connect Status entries are BLOCKED. Under advanced appliance settings I have configured to partition the appliances but now checked again and I made a typo (disbled instead of disabled).
Now it is corrected... I'm waiting for the block to be released.
Should I start a new log recording then or let's see how it behaves with (hopefully) correctly separated credentials?

@PrestonMcAfee
Copy link
Author

PrestonMcAfee commented Jan 20, 2025 via email

@PrestonMcAfee
Copy link
Author

We used the oven for an extended period without a single time out. 1.2.0-b1 seems to have fixed my issue. Thanks!

@bakoscsaba
Copy link

After correcting the typo and correctly separating the appliances the connection is stable. Thank you for your help!

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

No branches or pull requests

5 participants