forecast not updating because of api limit reached

bert1111 commented 3 weeks ago

Describe the bug forecast not updating because of api limit reached. It has worked for a few days I think and new I see this error.

To Reproduce Steps to reproduce the behavior: No Idea. I was in hospital after I updated to the latest version of solcast and didn't really monitor after I did the update.

Expected behavior That it updates. The api limit can't be reached yet.

Screenshots afbeelding

Logs

`Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.solcast_solar.solcastapi
Bron: custom_components/solcast_solar/solcastapi.py:2313
integratie: Solcast PV Forecast (documentatie, problemen)
Eerst voorgekomen: 08:06:12 (9 gebeurtenissen)
Laatst gelogd: 08:16:17

The API is busy, pausing 77 seconds before retry
The API is busy, pausing 92 seconds before retry
The API is busy, pausing 117 seconds before retry
The API is busy, pausing 132 seconds before retry
The API is busy, pausing 149 seconds before retry`
`Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.solcast_solar.solcastapi
Bron: custom_components/solcast_solar/solcastapi.py:2337
integratie: Solcast PV Forecast (documentatie, problemen)
Eerst voorgekomen: 08:18:46 (1 gebeurtenissen)
Laatst gelogd: 08:18:46

API was tried 10 times, but all attempts failed`
`Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.solcast_solar.solcastapi
Bron: custom_components/solcast_solar/solcastapi.py:1981
integratie: Solcast PV Forecast (documentatie, problemen)
Eerst voorgekomen: 08:18:46 (1 gebeurtenissen)
Laatst gelogd: 08:18:46

Forecast update for site x failed so not getting remaining sites`
`Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.solcast_solar.solcastapi
Bron: custom_components/solcast_solar/solcastapi.py:2005
integratie: Solcast PV Forecast (documentatie, problemen)
Eerst voorgekomen: 08:18:46 (1 gebeurtenissen)
Laatst gelogd: 08:18:46

At least one site forecast failed to fetch, so forecast has not been built`

autoSteve commented 3 weeks ago

This does not look like the API limit is exceeded.

The Solcast API was unavailable many times and the integration gave up. There are five attempts logged, but it gives up at ten, so has the log that you shared been altered?

Dutch:

Het lijkt er niet op dat de API-limiet wordt overschreden.

De Solcast API was vaak niet beschikbaar en de integratie stopte. Er zijn vijf pogingen geregistreerd, maar hij stopt bij tien. Is de log die je hebt gedeeld gewijzigd?

bert1111 commented 3 weeks ago

No I just copied it from the logs. I didn't alter anything. Maybe because I have two sites in one account? One facing east and one facing west.

autoSteve commented 3 weeks ago

No log timestamps to give a sense of timing makes things very hard to interpret.

It does interest me that there were only five retries reported, and you have two rooftops. Ten divided by two is... I will take a look at that, but I'm fairly certain that it should do up to ten tries per site. I wrote the code.

TL>DR: "API was tried 10 times, but all attempts failed." It failed. The API limit was not exceeded.

Did it fail because the integration has an issue? I doubt it. 4,500+ user experiences would agree with that. Did it fail because the Solcast API was issuing "429 error, go away we're busy" responses? Most likely.

But I could be wrong. I'm holding this issue open for now, but I strongly suggest that you try a 'developer tools' "Solcast PV Forecast: Update" (or run your fetch automation), or (if you're using the wonderful auto-update then) "Solcast PV Forecast: Force Update" and report back.

At times Solcast gets really busy, and the 429 responses seem to last ages. The other night I had a thirty minute period where I could get nothing from them.

autoSteve commented 3 weeks ago

@bert1111, thanks heaps for being a user by the way! Our interaction makes me want to book a trip back to the Netherlands. What an ace place.

(From a HAOS shell for me, via SSH... [Spoiler alert for a debug logging improvement coming]. The 'Troubleshooting' discussion has the details about how to get these logs.)

less /config/home-assistant.log, then type &solcast, then shift F to follow. Magic.

2024-10-17 16:23:06.432 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Checking for stale usage cache
2024-10-17 16:23:06.432 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site b68d-c05a-c2b3-2cf9
2024-10-17 16:23:06.433 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site b68d-c05a-c2b3-2cf9 lastday 2024-10-24 numhours 176
2024-10-17 16:23:06.442 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/b68d-c05a-c2b3-2cf9/forecasts
2024-10-17 16:23:06.442 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 16:23:07.539 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-17 16:23:07.539 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 2 to 3
2024-10-17 16:23:07.539 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-17 16:23:07.557 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-17 16:23:07.557 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-17 16:23:07.557 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 353 records returned
2024-10-17 16:23:07.795 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9069
2024-10-17 16:23:07.795 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-17 16:23:07.796 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.238 seconds
2024-10-17 16:23:07.800 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 83d5-ab72-2a9a-2397
2024-10-17 16:23:07.800 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site 83d5-ab72-2a9a-2397 lastday 2024-10-24 numhours 176
2024-10-17 16:23:07.800 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/83d5-ab72-2a9a-2397/forecasts
2024-10-17 16:23:07.801 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 16:23:08.321 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-17 16:23:08.322 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 3 to 4
2024-10-17 16:23:08.322 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-17 16:23:08.346 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-17 16:23:08.348 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-17 16:23:08.349 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 353 records returned
2024-10-17 16:23:08.586 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9069
2024-10-17 16:23:08.587 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-17 16:23:08.588 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.238 seconds
2024-10-17 16:23:08.946 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecast data from 2024-10-17 to 2024-10-24 contains all 48 intervals
2024-10-17 16:23:08.946 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-17 16:23:08.979 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 0.387 seconds
2024-10-17 16:23:09.376 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved dampened forecast cache
2024-10-17 16:23:09.399 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved undampened forecast cache
2024-10-17 16:23:09.400 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update completed successfully

bert1111 commented 3 weeks ago

I'm from Belgium by the way but you're close :).

I'm going to set for debug in a bit but after rebooting HA and trying the force update I now see following in my HA logs. Setting for the debug now.

`Deze fout is ontstaan door een aangepaste integratie.

Logger: custom_components.solcast_solar.solcastapi Bron: custom_components/solcast_solar/solcastapi.py:2237 integratie: Solcast PV Forecast (documentatie, problemen) Eerst voorgekomen: 10:46:40 (3 gebeurtenissen) Laatst gelogd: 10:47:10

Exception in http_data_call(): 'fetch': Traceback (most recent call last): File "/config/custom_components/solcast_solar/solcastapi.py", line 2158, in http_data_call resp_dict = self.tasks['fetch'].result() ~~^^^^^^^^^ KeyError: 'fetch'`

autoSteve commented 3 weeks ago

Damn. Soooo close. 🤣

The only way you could have hit that error is if the 'past' forecast data was trying to be fetched, indicating that your solcast.json in the config folder has been somehow killed. The integration is attempting to get the "estimated actuals" for the past, which makes no sense given your last forecast update was about five hours ago according to your screen shot.

What is the content of /config/solcast.json?

autoSteve commented 3 weeks ago

You haven't messed with your Solcast API key at all have you? There is an issue that I have fixed, yet not released yet on that front...

bert1111 commented 3 weeks ago

I just see someone else make a bug report with almost the same settings I am using. He uses two accounts and I only use one but he also uses the automatic updates. No I haven't changed anything.

The data in the solcast.json is ranging from "forecasts": [{"period_start": "2024-06-24T22:30:00+00:00" to "estimate90": 0.0}, {"period_start": "2024-10-24T21:30:00+00:00", "pv_estimate": 0.0, "pv_estimate10": 0.0, "pv_estimate90": 0.0}], "tally": 4.6573}}, "last_updated": "2024-10-17T08:46:39.226400+00:00", "version": 4}"

autoSteve commented 3 weeks ago

Very different settings. Very different issues i believe.

Debug logs for the win. I can't do much by guessing.

bert1111 commented 3 weeks ago

2024-10-17 10:54:58.529 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration solcast_solar which has not been tested by Home Assist
ant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2024-10-17 10:55:13.234 DEBUG (MainThread) [custom_components.solcast_solar] Auto-update options: {'auto_update': 1}
2024-10-17 10:55:13.235 DEBUG (MainThread) [custom_components.solcast_solar] Estimate to use options: {'key_estimate': 'estimate'}
2024-10-17 10:55:13.235 DEBUG (MainThread) [custom_components.solcast_solar] Attribute options: {'attr_brk_estimate': True, 'attr_brk_estimate10': False, 
'attr_brk_estimate90': False, 'attr_brk_site': False, 'attr_brk_halfhourly': True, 'attr_brk_hourly': False, 'attr_brk_detailed': False}
2024-10-17 10:55:13.235 DEBUG (MainThread) [custom_components.solcast_solar] Custom sensor options: {'customhoursensor': 1}
2024-10-17 10:55:13.235 DEBUG (MainThread) [custom_components.solcast_solar] Hard limit: {'hard_limit': 100000}
2024-10-17 10:55:13.236 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Configuration directory is /config
2024-10-17 10:55:13.249 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Sites cache exists
2024-10-17 10:55:13.249 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Connecting to https://api.solcast.com.au/rooftop_sites?format=json
&api_key=******PqOvKO
2024-10-17 10:55:14.128 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned status 200/Success in __sites_data()
2024-10-17 10:55:14.129 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing sites cache
2024-10-17 10:55:14.164 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Sites data: {'sites': [{'name': 'Thuis oost', 'resource_id': '4220
-0dc5-b46c-5b6e', 'capacity': 5, 'capacity_dc': 3.04, 'longitude': **.******, 'latitude': **.******, 'azimuth': -65, 'tilt': 30, 'install_date': '2022-02-
08T23:00:00.0000000Z', 'loss_factor': 0.94, 'tags': ['x']}, {'name': 'Thuis west', 'resource_id': '****************', 'capacity': 5, 'capacit
y_dc': 3.04, 'longitude': **.******, 'latitude': **.******, 'azimuth': 112, 'tilt': 30, 'install_date': '2022-02-21T23:00:00.0000000Z', 'loss_factor': 0.9
4, 'tags': ['**********']}], 'page_count': 1, 'current_page': 1, 'total_records': 2}
2024-10-17 10:55:14.165 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Sites loaded for ******PqOvKO
2024-10-17 10:55:14.167 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Usage cache exists for ******PqOvKO
2024-10-17 10:55:14.219 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Usage cache for ******PqOvKO last reset 2024-10-17 02:00:00
2024-10-17 10:55:14.219 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Usage loaded for ******PqOvKO
2024-10-17 10:55:14.220 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API counter for ******PqOvKO is 1/8
2024-10-17 10:55:14.220 DEBUG (MainThread) [custom_components.solcast_solar] Successful init
2024-10-17 10:55:14.220 INFO (MainThread) [custom_components.solcast_solar]
If all else fails, then open an issue and our community will try to
help: https://github.com/BJReplay/ha-solcast-solar/issues
-------------------------------------------------------------------
2024-10-17 10:55:14.416 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data cache /config/solcast.json exists, file type is <class 'dict'
>
2024-10-17 10:55:14.493 INFO (MainThread) [custom_components.solcast_solar.solcastapi] /config/solcast.json data loaded
2024-10-17 10:55:14.529 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data cache /config/solcast-undampened.json exists, file type is <c
lass 'dict'>
2024-10-17 10:55:14.532 INFO (MainThread) [custom_components.solcast_solar.solcastapi] /config/solcast-undampened.json data loaded
2024-10-17 10:55:15.026 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-17 contains all 48 records
2024-10-17 10:55:15.027 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-18 contains all 48 records
2024-10-17 10:55:15.028 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-19 contains all 48 records
2024-10-17 10:55:15.029 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-20 contains all 48 records
2024-10-17 10:55:15.032 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-21 contains all 48 records
2024-10-17 10:55:15.034 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-22 contains all 48 records
2024-10-17 10:55:15.036 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-23 contains all 48 records
2024-10-17 10:55:15.040 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-24 contains all 48 records
2024-10-17 10:55:15.040 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-17 10:55:15.092 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 0.558 seconds
2024-10-17 10:55:15.101 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Sun rise / set today: 08:06:12 / 18:43:03
2024-10-17 10:55:15.103 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Auto update: Total seconds 38211, divisions: 4 updates, interval:
 9552 seconds
2024-10-17 10:55:15.103 INFO (MainThread) [custom_components.solcast_solar.coordinator] Auto-update will update forecasts 4 times between sunrise and suns
et
2024-10-17 10:55:15.103 INFO (MainThread) [custom_components.solcast_solar.coordinator] Auto-scheduled forecast update for today at 13:24:36, 16:03:48
2024-10-17 10:55:15.104 INFO (MainThread) [custom_components.solcast_solar.coordinator] Auto-scheduled forecast update for tomorrow at 08:07:52, 10:46:09,
 13:24:26, 16:02:43
2024-10-17 10:55:15.105 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Started task listeners
2024-10-17 10:55:15.106 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Started task check_fetch
2024-10-17 10:55:15.106 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Started task midnight_update
2024-10-17 10:55:15.106 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Finished fetching solcast_solar data in 0.000 seconds (success: T
rue)
2024-10-17 10:55:17.688 DEBUG (MainThread) [custom_components.solcast_solar] UTC times are converted to Europe/Brussels

bert1111 commented 3 weeks ago

in the integration I now see this. afbeelding

autoSteve commented 3 weeks ago

Thuis oost and west look like they survived a perfectly normal startup sequence, with auto-update enabled. Good on you!

Perfect logs for the job.

API used is showing as '1'. This is weird for a two-site set up, but may be explained by a previous failure. The integration tracks this in a solcast-usage.json cache, so the content of that file in the `/config' folder will confirm that.

You've got an update scheduled for today at 13:24:36. Let's see if it turns to custard or not. Post logs, but I'm fairly certain it will succeed. (Your earlier error about the 'fetch' task I cannot work out. I have tried this code path many times without incident.

hwb45 commented 3 weeks ago

I think it is the api is busy, this is the second morning in a row that the 09:xx has failed owing to 429 error, here are my logs from today.

[edit by @autoSteve, your post is weird Henry! I cannot format the logs as a code block, so here's the best that happens...]

2024-10-17 08:07:52.740 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration solcast_solar which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2024-10-17 09:36:00.415 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 16 seconds before retry
2024-10-17 09:36:16.440 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 43 seconds before retry
2024-10-17 09:36:59.466 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 48 seconds before retry
2024-10-17 09:37:47.572 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 62 seconds before retry
2024-10-17 09:38:49.609 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 81 seconds before retry
2024-10-17 09:40:10.640 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 103 seconds before retry
2024-10-17 09:41:53.679 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 106 seconds before retry
2024-10-17 09:43:39.743 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 127 seconds before retry
2024-10-17 09:45:46.781 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] The API is busy, pausing 147 seconds before retry
2024-10-17 09:48:13.900 ERROR (MainThread) [custom_components.solcast_solar.solcastapi] API was tried 10 times, but all attempts failed
2024-10-17 09:48:13.900 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update for site 02d4-edbc-faba-cb5b failed
2024-10-17 09:48:13.900 ERROR (MainThread) [custom_components.solcast_solar.solcastapi] At least one site forecast failed to fetch, so forecast has not been built

Cheers Henry

bert1111 commented 3 weeks ago

2024-10-17 11:27:17.736 INFO (MainThread) [custom_components.solcast_solar] Service call: update_forecasts
2024-10-17 11:27:17.737 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Checking for stale usage cache
2024-10-17 11:27:17.739 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 4220-0dc5-b46c-5b6e
2024-10-17 11:27:17.740 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site xxxxxxxxxx lastday 2024-10-24 numhou
rs 181
2024-10-17 11:27:17.741 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/xxxxxxxxxxxxxxx/forecasts
2024-10-17 11:27:17.741 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 11:27:18.857 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-17 11:27:18.857 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, using force fetch so not incrementing API counter
2024-10-17 11:27:19.414 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-17 11:27:19.415 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-17 11:27:19.415 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 363 records returned
2024-10-17 11:27:19.480 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 5855
2024-10-17 11:27:19.482 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-17 11:27:19.892 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.477 seconds
2024-10-17 11:27:19.898 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site cee7-9c91-f834-32ad
2024-10-17 11:27:19.899 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site xxxxxxxxxxxxxxx lastday 2024-10-24 numhours 181
2024-10-17 11:27:19.902 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/cxxxxxxxxxxxxxxxxxxxxxxx/forecasts
2024-10-17 11:27:19.902 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 11:27:21.066 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-17 11:27:21.067 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, using force fetch so not incrementing API counter
2024-10-17 11:27:21.614 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-17 11:27:21.615 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-17 11:27:21.615 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 363 records returned
2024-10-17 11:27:21.664 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 5855
2024-10-17 11:27:21.666 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-17 11:27:22.059 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.444 seconds
2024-10-17 11:27:22.547 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-17 contains all 48 records
2024-10-17 11:27:22.548 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-18 contains all 48 records
2024-10-17 11:27:22.549 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-19 contains all 48 records
2024-10-17 11:27:22.550 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-20 contains all 48 records
2024-10-17 11:27:22.551 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-21 contains all 48 records
2024-10-17 11:27:22.554 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-22 contains all 48 records
2024-10-17 11:27:22.556 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-23 contains all 48 records
2024-10-17 11:27:22.559 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Data for 2024-10-24 contains all 48 records
2024-10-17 11:27:22.560 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-17 11:27:22.612 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 0.546 seconds
2024-10-17 11:27:22.947 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved forecast cache /config/solcast.json
2024-10-17 11:27:23.003 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved forecast cache /config/solcast-undampened.json
2024-10-17 11:27:23.003 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update completed successfully

autoSteve commented 3 weeks ago

And normal service returns, @bert1111. Looks perfect.

bert1111 commented 3 weeks ago

But why does it throw an error that the api limit was exceeded? Or isn't that what the error was? Anyway I'll keep an eye on it.

autoSteve commented 3 weeks ago

I think it is the api is busy

@hwb45, they do get feisty at times. I have built in retries to try tenaciously, unlike Oziee versions that just tossed their toes in the air at the first smell of a 429. But sometimes... bad things happen.

Unexplained things have happened in this issue report, including a raised exception, which should not happen, nor be possible, but that may be because @bert1111 (to misquote @BJReplay, and no offence intended) may have tried sacrificing a chicken or some other unnatural act to try and revive something that was simply a temporary error, as noted in the readme.

(You didn't go the voodoo route @bert1111, did you, by changing API keys and expecting a different result? 🤣 I'm still interested in the exception that you got that should not be, though. I cannot explain it, and that code was tested many times just days ago. Weird. If you did use voodoo it would be useful to know...)

autoSteve commented 3 weeks ago

But why does it throw an error that the api limit was exceeded? Or isn't that what the error was? Anyway I'll keep an eye on it.

I didn't see anywhere that the limit was exceeded. I just saw that it gave up after ten attempts at getting one of your sites. Ten tries. API limit ten. Coincidence.

bert1111 commented 3 weeks ago

No voodoo here 🤣. I wish I understood HA and programming better so I could be of more assistance. I tried but my memory and concentration issues aren't helping being a programmer.

bert1111 commented 3 weeks ago

This is the log from the last automatic update.

2024-10-17 13:20:00.330 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Forecast will update in 276 seconds
2024-10-17 13:24:36.332 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Checking for stale usage cache
2024-10-17 13:24:36.334 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 4220-0dc5-b46c-5b6e
2024-10-17 13:24:36.335 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site 4220-0dc5-b46c-5b6e lastday 2024-10-24 numhours 179
2024-10-17 13:24:36.335 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/4220-0dc5-b46c-5b6e/forecasts
2024-10-17 13:24:36.336 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 13:24:37.522 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-17 13:24:37.523 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 1 to 2
2024-10-17 13:24:37.523 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-17 13:24:38.091 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-17 13:24:38.091 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-17 13:24:38.092 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 359 records returned
2024-10-17 13:24:38.142 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 5855
2024-10-17 13:24:38.143 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-17 13:24:38.548 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.457 seconds
2024-10-17 13:24:38.553 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site cee7-9c91-f834-32ad
2024-10-17 13:24:38.555 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site cee7-9c91-f834-32ad lastday 2024-10-24 numhours 179
2024-10-17 13:24:38.556 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/cee7-9c91-f834-32ad/forecasts
2024-10-17 13:24:38.556 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-17 13:24:39.190 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-17 13:24:39.195 ERROR (MainThread) [custom_components.solcast_solar.solcastapi] API allowed polling limit has been exceeded, API counter set to 8/8
2024-10-17 13:24:39.196 WARNING (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update for the last site queued failed (cee7-9c91-f834-32ad) so not getting remaining sites - API use count may be odd
2024-10-17 13:24:39.196 ERROR (MainThread) [custom_components.solcast_solar.solcastapi] At least one site forecast failed to fetch, so forecast has not been built
2024-10-17 13:24:39.210 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Next forecast update scheduled for 2024-10-17 16:03:48

autoSteve commented 3 weeks ago

Please format logs enclosed in tripple back-ticks. ```

autoSteve commented 3 weeks ago

Back ticks and then GitHub will get you. ```

Not single quotes '''. If you want to quote a single thing, lile entity.my_thing, then enclose it inline with single back-ticks around the words using `.

What I think has happened here is that the internal counter in the integration of API used was one, then two, while Solcast subsequently says different. Then the integration adjusts based on the specific API response of usage counter exceeded. This will reset at midnight UTC.

autoSteve commented 3 weeks ago

Furher supported by

API returned data, using force fetch so not incrementing API counter

You've been force-fetching, and the integration specifically does not keep count of this with auto-update enabled. It is by design.

Sadly Solcast removed the API call to ge the current state of API usage, so we've got nothing except internal monitoring until they bring the option to get it back. Maybe they will, maybe they won't...

A 'force fetch' defeats the counter on purpose. It has to, and so bad things can happen if you cause them to be bad.

autoSteve commented 3 weeks ago

(If you're listening, @billy-solcast, how about into the suggestions box: Including api used in the response for a forecast fetch? That's low cost, single call and could be used to re-adjust an internal counter...)

BJReplay commented 3 weeks ago

Should force-fetches decrement available API count?

If only to avoid issues like this one being raised 🤣?

At least until @billy-solcast comes to the party with a remaining API count in the API response (though, TBF, I expect that's a significant change for them to consider, as it would either require an optional parameter for the request to say that you're asking for it, or a added component in the returned json, that might be breaking for people not expecting it).

bert1111 commented 3 weeks ago

Should force-fetches decrement available API count?

If only to avoid issues like this one being raised 🤣?

Well I just want to say, that wasn't the issue I raised. And it seems although the call failed it used up api calls somehow. I did use force fetch but not that many times that all my calls where used for yesterday. I believe that I used six that returned data when it failed due to calls being used up. The other calls returned api is busy so my total of ten shouldn't have been used up and it should have failed because of that at a later time.

BJReplay commented 3 weeks ago

Well I just want to say, that wasn't the issue I raised.

I know, but...

I believe that I used six that returned data

The thing is that every call uses one of your calls.

@autoSteve made a judgement call that it was reasonable for a user might want to force the integration to refresh the forecast - even if the integration thought that all calls were used - so changed the force fetch call to both ignore the number of calls that had been made - so that it would run even if the count was already at the limit - and not increase the count of calls made.

So, if you made say six forced calls yesterday, even if you weren't complaining about this, this is what might have happened:

You might have thought that the force fetch call neither used an API count nor increased the used count - but as far as Solcast is concerned, each one very much did use an API count.

The integration didn't know you'd made six calls - because it wasn't counting.

Later on - after only 2 calls that it was counting - it got the error from Solcast indicating that you had exceeded your limit.

So, as Steve pointed out - it now knows that the limit has been exceeded, so it sets its internal counter to the limit (which is 8 - as you've configured).

That's why I suggested we change the way force-fetch works (slightly) - it ignores the fact that the integration thinks the limit might have been exceeded (so if I user thinks or knows that it hasn't), it at least tries), but it still attempts to fetch. But it increments the API used count otherwise.

BJReplay commented 3 weeks ago

Well I just want to say, that wasn't the issue I raised.

And, in regards to the issue you did originally raise - we're not ignoring it - but after the fact, without timestamped logs, it's hard to say what did happen.

What we do know now, is that things appear to be working as expected:

Solcast does occasionally get very busy, and despite up to 10 retries, a forecast will fail to be fetched.
This can sometimes happen after one out of two arrays (sites) are fetched, leading to an odd number of API calls being used up.
The integration will use a call to initialise if the cached configuration files require this, for various reasons, again ending up using an odd number of API calls for a two array (site) system.

And it seems although the call failed it used up api calls somehow.

And, if that's the case, whilst it's possible that, as far as Solcast is concerned, they've considered that you've made a successful API call, but returned a failure to the integration, there's not much we can do about that - other than refund the fees you've paid for access to the integration and to Solcast, of course 😉 - but again, that's highly unlikely. It's more likely that it hasn't used up API calls, but force fetches have.

autoSteve commented 3 weeks ago

Regarding not incrementing the API use counter for a force update, this may be a silly thing to be doing @BJReplay, because it does leave a bit of an information gap.

Rumbing about in the back of my head is the notion of a triad of API limit, API used, and auto-update API used. All three could be displayed on the dignostics page giving far greater situational awareness.

What would result however, is the need to add yet another configuration option (involving Urdu) that would be something like "API calls to use for auto-update" or a name far more thought through.

I'm not going to answer the call of that rumbling rumiation for now, preferring to see how many folks step on the API use rake head and get smacked in the face with the handle.

The present implementation is simple. I like simple. Simple shit doesn't break. (Until it does...)

BJReplay commented 3 weeks ago

a triad of API limit, API used, and auto-update API used

Seems overly complex

is the need to add yet another configuration option

Seems overly complex

referring to see how many folks step on the API use rake head and get smacked in the face with the handle

Seems fair enough

The present implementation is simple. I like simple.

Agreed.

Perhaps the only variation would be to ignore the fact that you might appear to be at the limit, and attempt an update if already at the limit if force is called.

BJReplay commented 3 weeks ago

Perhaps the only variation would be to ignore the fact that you might appear to be at the limit, and attempt an update if already at the limit if force is called.

Just revert the change here?

https://github.com/BJReplay/ha-solcast-solar/blob/e9a792ba4cfd1f16e33141913d494d6ed279269f/custom_components/solcast_solar/solcastapi.py#L2321

But not the change higher up that checks the current limit

autoSteve commented 3 weeks ago

Just revert the change here?

Yeah, nah. It's a force fetch. Can't update the API used, as that's against the current simple implementation "rules" of "auto-update should only mess with that counter or it will get lost".

Force is force. It's up to the user to be mindful of actual total used count above what auto-update will consume. Which brings my brain back to instrumentation of this, and added complexity, which brings my brain back to Urdu can't deal.

BJReplay commented 3 weeks ago

Fair enough.

BJReplay commented 3 weeks ago

P.S. Have been re-netflixing Three Body Problem. Is still good second time around. Less blurry, too.

matomatusov commented 3 weeks ago

Hi, The total API limit was not used for me today. I have set Automatic update of forecasts from sunrise to sunset It was OK with automation in the old version.

Don't know what the problem could be?

API limit

Thanks

autoSteve commented 3 weeks ago

Hi, The total API limit was not used for me today. I have set Automatic update of forecasts from sunrise to sunset It was OK with automation in the old version.

You are going to need to provide a tonne more information for anyone to say why @matomatusov.

How does your issue remotely relate to hitting the API limit?
When you say "automation" was that an HA automation used with "the old version", or the auto-update feature of the integration?
What version are you running?
What version was "the old version"?
What happened in the logs?
Turn info level logging on for the integration and restart (if info is not already your default). The proposed update times throughout the day will be logged on startup. Are these wrong?
When is UTC midnight for you (i.e. what constitutes "a day", i.e. when is usage reset)?
At what time of day is six calls used up as shown?
When was the first forecast fetch of the day, and what was the API count at the time? Did this align with the proposed updates logged at startup?

I could keep asking questions...

autoSteve commented 3 weeks ago

Despite providing very little information @matomatusov, I think I have an answer for you.

Note in my diagnostic usage the value says 8. This is wrong. I have used two API calls in this UTC day period, and the logged forecast fetches reflect this. Now open the diagnostic sensor. I expect you will see something like this. The history shows correctly, yet the API used does not.

So this is an instrumentation bug, and thanks for pointing it out. It will be fixed in a future version.

BJReplay commented 3 weeks ago

Is it a bug with multi-array systems?

I have a tell-tale on one of my background dashboards where I have tweaks and controls, and it doesn't seem to miss a beat.

History doesn't go back that far because I'm in the habit of uninstalling and re-installing for testing 🤣

I set it up when it appeared that updates weren't happening (that was around that time that the UTC midnight resets weren't happening, but that was ages ago).

bert1111 commented 3 weeks ago

I don't know if any one else has problems with the api calls but yesterday every single one failed with API busy except the one at 5:32 AM. Today up until now the same result, API busy try again. Does everyone have the same problem then or not? I tried logging in to my solcast account and downloading the JSON from there and that works, probably until my API calls run out? Did solcast maybe change something you are not aware of? Just trying to help.

gcoan commented 3 weeks ago

I don't know if any one else has problems with the api calls but yesterday every single one failed with API busy except the one at 5:32 AM.

Similar story for me.

Yesterday, 19th, 1am took 4 retries, 6am 2 retries, 10am failed after 10 retries, 1pm failed after 10 retries, 6pm took 2 retries

Today 20th 1am took 6 retries, 6am 2 retries, 10am failed after 10 retries

autoSteve commented 3 weeks ago

There's not enough O's in smooth to describe my today...

2024-10-20 09:45:48.952 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 09:45:48.952 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 6 to 7
2024-10-20 09:45:48.952 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 09:45:48.983 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 09:45:48.983 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 09:45:48.984 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 367 records returned
2024-10-20 09:45:49.603 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 09:45:49.604 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 09:45:49.604 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.620 seconds
2024-10-20 09:45:49.606 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 83d5-ab72-2a9a-2397
2024-10-20 09:45:49.607 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site 83d5-ab72-2a9a-2397 lastday 2024-10-27 numhours 183
2024-10-20 09:45:49.608 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/83d5-ab72-2a9a-2397/forecasts
2024-10-20 09:45:49.608 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-20 09:45:50.152 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 09:45:50.152 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 7 to 8
2024-10-20 09:45:50.152 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 09:45:50.168 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 09:45:50.169 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 09:45:50.175 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 367 records returned
2024-10-20 09:45:50.549 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 09:45:50.549 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 09:45:50.550 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.375 seconds
2024-10-20 09:45:52.998 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecast data from 2024-10-20 to 2024-10-27 contains all 48 intervals
2024-10-20 09:45:52.998 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-20 09:45:53.034 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 2.483 seconds
2024-10-20 09:45:53.378 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved dampened forecast cache
2024-10-20 09:45:53.457 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved undampened forecast cache
2024-10-20 09:45:53.464 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update completed successfully
2024-10-20 09:45:53.544 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Next forecast update scheduled for 2024-10-20 13:04:50
2024-10-20 11:00:00.520 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Reset API usage
2024-10-20 11:00:00.523 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 11:38:15.115 WARNING (Thread-3 (_thread_main)) [roombapy.remote_client] Unknown disconnection error: ID=16.Kindly use https://github.com/pschmitt/roombapy/issues/new
2024-10-20 11:38:15.116 WARNING (Thread-3 (_thread_main)) [roombapy.roomba] Unexpectedly disconnected from Roomba 192.168.10.205, code UNKNOWN_ERROR
2024-10-20 11:38:15.116 WARNING (Thread-3 (_thread_main)) [roombapy.remote_client] Unknown disconnection error: ID=16.Kindly use https://github.com/pschmitt/roombapy/issues/new
2024-10-20 11:38:15.116 WARNING (Thread-3 (_thread_main)) [roombapy.roomba] Unexpectedly disconnected from Roomba 192.168.10.205, code UNKNOWN_ERROR
2024-10-20 13:00:00.116 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Forecast will update in 290 seconds
2024-10-20 13:04:50.119 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Checking for stale usage cache
2024-10-20 13:04:50.120 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site b68d-c05a-c2b3-2cf9
2024-10-20 13:04:50.120 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site b68d-c05a-c2b3-2cf9 lastday 2024-10-27 numhours 179
2024-10-20 13:04:50.121 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/b68d-c05a-c2b3-2cf9/forecasts
2024-10-20 13:04:50.121 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-20 13:04:50.819 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 13:04:50.819 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 0 to 1
2024-10-20 13:04:50.820 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 13:04:50.846 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 13:04:50.847 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 13:04:50.847 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 359 records returned
2024-10-20 13:04:51.145 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 13:04:51.145 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 13:04:51.145 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.298 seconds
2024-10-20 13:04:51.148 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 83d5-ab72-2a9a-2397
2024-10-20 13:04:51.154 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site 83d5-ab72-2a9a-2397 lastday 2024-10-27 numhours 179
2024-10-20 13:04:51.155 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/83d5-ab72-2a9a-2397/forecasts
2024-10-20 13:04:51.155 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-20 13:04:51.627 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 13:04:51.627 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 1 to 2
2024-10-20 13:04:51.627 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 13:04:51.644 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 13:04:51.645 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 13:04:51.645 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 359 records returned
2024-10-20 13:04:51.992 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 13:04:51.992 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 13:04:51.993 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.348 seconds
2024-10-20 13:04:54.157 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecast data from 2024-10-20 to 2024-10-27 contains all 48 intervals
2024-10-20 13:04:54.157 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-20 13:04:54.204 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 2.210 seconds
2024-10-20 13:04:54.655 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved dampened forecast cache
2024-10-20 13:04:54.846 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved undampened forecast cache
2024-10-20 13:04:54.846 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update completed successfully
2024-10-20 13:04:55.006 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Next forecast update scheduled for 2024-10-20 16:24:20
2024-10-20 16:20:00.116 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Forecast will update in 260 seconds
2024-10-20 16:24:20.156 DEBUG (MainThread) [custom_components.solcast_solar.coordinator] Checking for stale usage cache
2024-10-20 16:24:20.157 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site b68d-c05a-c2b3-2cf9
2024-10-20 16:24:20.157 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site b68d-c05a-c2b3-2cf9 lastday 2024-10-27 numhours 176
2024-10-20 16:24:20.159 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/b68d-c05a-c2b3-2cf9/forecasts
2024-10-20 16:24:20.159 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-20 16:24:20.870 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 16:24:20.871 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 2 to 3
2024-10-20 16:24:20.871 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 16:24:20.894 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 16:24:20.894 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 16:24:20.894 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 353 records returned
2024-10-20 16:24:21.290 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 16:24:21.290 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 16:24:21.291 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.396 seconds
2024-10-20 16:24:21.295 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Getting forecast update for site 83d5-ab72-2a9a-2397
2024-10-20 16:24:21.295 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Polling API for site 83d5-ab72-2a9a-2397 lastday 2024-10-27 numhours 176
2024-10-20 16:24:21.296 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch data url: https://api.solcast.com.au/rooftop_sites/83d5-ab72-2a9a-2397/forecasts
2024-10-20 16:24:21.297 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetching forecast
2024-10-20 16:24:21.855 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Fetch successful
2024-10-20 16:24:21.855 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] API returned data, API counter incremented from 3 to 4
2024-10-20 16:24:21.855 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Writing API usage cache file: /config/solcast-usage.json
2024-10-20 16:24:21.916 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session returned data type <class 'dict'>
2024-10-20 16:24:21.916 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP session status 200/Success
2024-10-20 16:24:21.917 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] 353 records returned
2024-10-20 16:24:22.426 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecasts dictionary length 9213
2024-10-20 16:24:22.427 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Undampened forecasts dictionary length 1056
2024-10-20 16:24:22.427 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] HTTP data call processing took 0.510 seconds
2024-10-20 16:24:25.077 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Forecast data from 2024-10-20 to 2024-10-27 contains all 48 intervals
2024-10-20 16:24:25.077 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Calculating splines
2024-10-20 16:24:25.109 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Build forecast processing took 2.679 seconds
2024-10-20 16:24:25.749 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved dampened forecast cache
2024-10-20 16:24:26.148 DEBUG (MainThread) [custom_components.solcast_solar.solcastapi] Saved undampened forecast cache
2024-10-20 16:24:26.148 INFO (MainThread) [custom_components.solcast_solar.solcastapi] Forecast update completed successfully

BJReplay commented 3 weeks ago

Two 429s today, otherwise OK.

Perhaps more load in your hemisphere?

BJReplay commented 3 weeks ago

Did solcast maybe change something you are not aware of?

Not that we're aware of.

Just trying to help.

Speculation is not actually helping.

I am going to close this issue.

I don't believe that it represents a problem that can be traced back to anything other the Solcast servers being busy.

https://status.solcast.com/ doesn't tell us there is anything wrong and the history doesn't suggest that there have been problems since June

BJReplay / ha-solcast-solar

forecast not updating because of api limit reached #187