-
Notifications
You must be signed in to change notification settings - Fork 38
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
Problem on update call (unable to get sensor value 'tally' Traceback) (using multiple Solcast accounts) #42
Comments
@ffm777 Did you notice the API Limit Exceeded warning on line 25 of the file? |
What's your API call quota, @ffm777? 50? 10? And what is the content of your /config/solcast-usage.json? Does it match your expected quota? Does this file even exist? |
Not getting the forecast should not result in a fail to get the rooftop site total today, but I can't yet see what is causing this. The value should just not change. |
@ffm777, are you clever enough to update some code as a test, please? I had rigged What this change below to the function http_data() does is to build the forecast using the last forecasts data that had been successfully gatherered. This is where the 'tally' is included (but I'm not sure why it went missing). Replace http_data() with the below, restart integration and then intentionally bust through the API limit at the end of the day. Or do it at a time of day when 10/10 calls should already be used up so that you don't waste any. (I just did so, and what my log read is below the code.) Note that this code also prevents frequent forecast acquisition, not gathering if fifteen minutes since last has not elapsed. That is experimental code to try and avoid another issue that another user and I encountered, so if it impacts you then remove those two lines near the top.
|
I will test. But I have also discovered another error concerning the API used counter. When using 2 API keys, then the calls are added. This should not be the case. For example, today I made 4 API calls to each of my accounts. With my quota of 10 calls, I still have 6 calls per account left. However, the integration counts 8 API calls used, which is not correct. When using 2 API keys, then the integration should not add the API call from both accounts but rather should only count the calls to one of the accounts! That was also the reason why yesterday evening the integration said that the API limit is exceeded, which it was not. I checked my solcast accounts and there were still API calls left! |
This is fair and square a bug. I'll take a look. I'll need to add separate counters for each API key. |
Righto, @ffm777. Commit 9373df6 is experimental. This alters solcastapi.py to account for multiple API key site usage information, and I'd appreciate a test from someone who actually has this set-up. Initial test for one site/two arrays is good for me. I have also incorporated the experimental code above. The code tracks the individual quotas, not assuming that both sites have the same quota. e.g. Someone might have 50 for their initial site, and 10 for a new hobbyist site. In the above example, asking the integration "how many calls can I make?" it would answer: 60, and for usage, the sum of both sites. That is what it is. So grab solcastapi.py from the commit, make a backup of your current file, replace, and re-start to see what happens! You should get two files in /config called solcast-usage-[sitekey].json, unlike everyone else with one site that just has a solcast-usage.json file. If this works, you can delete /config/solcast-usage.json. |
Hold off @ffm777 . The experimental "do not call within fifteen minutes of last call" is not working...
|
I started testing the new version. First API call looks good. No more errors. API counter is also correct. Only minor thing that I discovered is a Solcast warning "SOLCAST - Retries exhausted gathering rooftop sites data, last call result: 429, using cached data if it exists" when I restarted HA to enable the new version. Does the integration try to retrieve data on start-up? I would prefer the integration only calling the API when triggered by the update_forecasts service. |
Nope, @ffm777. And it looks like it used the cached rooftop sites data perfectly, so no foul, and that makes me smile. There are some API calls that do not count against your daily quota. And I will use them. Chiefly for the question "How many calls am I allowed?", and that is un-metered. Secondly, "What rooftop sites do I have?", and again un-metered. You have to be able to ask those questions before you can interact with the API, so they let you at will. Unless they're busy... And therein lies the MOST COMMON cause of 429 errors. "Go AWAY hobbyist! We're A LITTLE BUSY RIGHT NOW BECAUSE OF ALL YOU HOBBYISTS!" (tell your mates, please...) So... enter autoSteve's caching code. If either call fails, then I get the data out of a cache. If the cache doesn't exist? Well, I guess folks raise an issue here, and we tell them to go restart a few times, and review logs, and re-think things if it isn't an integration problem, which is most of the time, and probably why Oziee committed GitHub suicide. 🤣 So no. I have to make that call to see whether anything has changed. It if fails? No problemo, unless there's been a change... |
As an aside, the sequence is:
I have built in a 'back-off' retry for the forecast get to cope with "GO AWAY! We're busy" from Solcast. Basically this delays for 30+(random 0-30 secs), then 60+(random 0-30 secs), then 120+(random 0-30 secs), etc. for five times. You won't notice that delay, and it usually succeeds, so probably won't even go hunting for it in the logs. But I'll bet you see it from time-to-time if you do actually look. Finally, the reason that I didn't do a back-off retry for initial rooftop sites and API quota use. That would introduce potential significant delay for the startup of the integration. And it's not that important as long as the info has been gathered on a prior restart. |
Do let me know how things go over the next day, @ffm777. If it's all pleasing for you then I'll raise a pull request for inclusion in the next version. |
I updated to V4.0.31 last night, which ran OK. I have an automation that only updates once per day at Sunrise - 7 minutes, so reasonably random from the perspective of limiting Solcast calls. I had a "Unable to get sensor value 'tally'" error when I looked at the logs from that time earlier today, and as a test I've just made a service call to Solcast PV Forecast: Update and got the same error. However, if I check the contents of the solcast.json file, a 'tally' entry exists for each of my roofs, and each has a sensible value. I have so far today used 6 of my 10 Solcast api calls Log: 2024-06-18 22:46:00.343 ERROR (MainThread) [custom_components.solcast_solar.sensor] SOLCAST - unable to get sensor value 'tally' Traceback (most recent call last): Hope this is of some help |
Hey, @ProphetOfDoom. 4.0.31 does not include this code for http_data() in solcastapi.py. That is currently in a draft pull request. If you change this section of code and restart Solcast integration do things go better?
|
@autoSteve Just gave your suggestion a whirl Actions:
Log entries filtered by "solcast" (so no solcast errors or warnings): 2024-06-19 02:04:53.483 INFO (MainThread) [homeassistant.setup] Setting up solcast_solar File updates:
API Calls:
Roof tallys:
I'll leave it at that for now and see what happens when my solcast automation runs at (sunrise - 7) mins, which is about 04:30 BST and let you know later today |
Hi Steve, |
Replace this function in coordinator.py, @ffm777.
|
Actually not, @ProphetOfDoom. I don't think you're running this proposed code. Just 4.0.31 with the mod above, so don't. |
Ok. Replaced the code and restarted. Let's see how it goes. I keep you posted. The update call after restarting the integration this morning (before replacing the code) also went well. No problems. |
System details: http_data() in solcastapi.py updated as posted above Solcast automation ran at 04:46 BST solcast.json file updated 2 api calls used out of 10 all sensors populated Solcast entries in log file: |
Looks encouraging, @ProphetOfDoom. |
All still running smoothly, @ffm777 & @ProphetOfDoom? We've had a UTC counter reset by now, so any more "tally" or midnight reset issues? |
Almost. All update calls went well. But on one of my update calls this morning, I received a tally error when the Solcast API was busy. See attached logs. But all update calls worked and values were updated correctly. |
That debug log is likely going to be SUPER helpful @ffm777. The "tally" issues happen between retries. Whoa. So the "tally" key in the dict must go missing between the start of poll and end of poll, whether that be a success or a failure. Great capture! |
@autoSteve http_data() in solcastapi.py updated as posted above Solcast automation ran at 04:46 BST solcast.json file updated 2 api calls used out of 10 all sensors populated Solcast entries in log file: I assume that if you wanted any detailed debug logging I would not only have to set my configuration.yaml like this:
but also turn on "Enable debug logging" in the Solcast configuration dialog |
Sooo... @ffm777. The "unable to get sensor value 'tally'" messages presumably go away after a successful forecast poll, yes? You don't show what happens after ultimate success in the log, so presumably it was uninteresting. This has really got me scratching my head, but I will find it... Some time between a commencement of poll, and the ultimate result of the poll, whether successful or not, the value self._data["siteinfo"][rooftopid]["tally"] goes away. I cannot see why at the moment. If there is an appreciable delay (like because Solcast is busy), then HA tries to read this sensor value, and it doesn't exist, so the exception occurs. Yet, it should persist the http_data() call from all the code staring that I've done. I continue to stare with a furrowed brow... Any other staring from anyone else would be appreciated. |
Yes. After the successful forecast poll they go away. My system ran two more forecasts updates at 11:45 am and 2:35 pm which were both uneventful. Everything went smoothly. No more tally errors. |
Thought as much. At this stage I have absolutely nothing to explain why it is happening. HA calls http_data(), which calls http_data_call() for each rooftop, which then calls fetch_data() for each rooftop. At no stage is self._data["siteinfo"][rooftopid]["tally"] or self._data["siteinfo"][rooftopid] or self._data["siteinfo"] messed with before a successful call is had from what I can see. So there is something that I can not see yet that is causing it to be temporarily lost. |
The good thing is at least that the integration works just fine even with the error. So no crashes or anything. But of course. Would be nice to get rid of that error. |
I could just suppress it... (Evil laugh...) But no. I will not. |
For now, I just cannot explain this loss of "tally" during the retry. I have spent literally hours staring at the code and can come up with nothing, which is exasperating given I do Python for a day job. This integration code is not that complex! |
@autoSteve Just a mad thought. @ffm777 has two api keys. Does handling one "interfere" with the data of the other in some way? |
It's not mad at all. I had the same thought, @ProphetOfDoom. It was @ffm777's second account call of two that failed, and that resulted in retry with "tally" issues for the duration. The first account was all good with no retry. I have one account, and have never seen this, ever, so there may definitely be something behind that. If it was the first account of two retrying and getting the "tally" thing, then fair enough, although I've still got nothing if this happens. But should it always be the second account on retry doing this??? THEN I have something. Well, then I have not much of something, because that would not make sense, but at least it's a pattern to chase... I just can't see what could be behind it in the code. Gha! |
It is also interesting (to me) that account two, rooftop one completely failed even after back-off retry, virtually confirming that the Solcast API is getting real hard for hobbyists to work with, necessitating lengthy retries. I was right to code this. This poll was around the turn of the hour, giving up at around seven minutes past the hour. That's not flash from a service provider point of view. Then account two, rooftop two succeeded after a couple of retries at around eight and a half minutes past the hour. Same thing almost happened to me yesterday with one account and two arrays. I might need to be even more feisty and extend the back-off retry for one more iteration. (But I digress from "I got nothin'"...) |
Today I set my automation for on-the-hour forecast gather to try and examine failure / retry scenarios. All of them have succeeded without any retry. 🤦🏻😂 |
So as I said, I cannot see why the 'tally' is going missing. Attempted mitigation time, given it appears to be transient while the retry is occurring. Try the following: Replace line 399 in solcastapi.py, which is:
with this...
If 'tally' cannot be found, then |
(Edited. Sorry.) |
I just switched to 4.0.32. Let's see how it goes. Didn't have any more tally errors yesterday and today. Thanks @autoSteve for your efforts to get everything working nicely and smoothly again! |
🫰 @ffm777. The work-around for 'tally' missing just results in the site sensor showing as Unknown. Does anyone ever use that anyway??? I certainly don't... For me, it's these... ![]() |
Updated to V4.0.32 and restarted HA. Reminder that my solcast automation is set to run at Sunrise - 7 mins, so approx 04:46 BST solcast.json file NOT updated 2 api calls used out of 10 all sensors populated Solcast entries in log file: All looking good so far, thanks to all. |
So, @ProphetOfDoom, Your Solcast diagnostics will maybe show 'Unknown' for the NE/SW Roofs during times where the integration is retrying a forecast poll. And that's a real 'maybe'. I can't explain why it happens, but it just does. Once the retrying is done the values will come back. At least it doesn't error out now. |
Given the pre-release v4.0.32, could I get you to respond favourably or not in that discussion whether the whole 'tally' thing has been mitigated now? I'm trying to gather data points that will help inform GA of that release. |
I already posted under "Discussion". 4.0.32 seems to work fine on my end, but I did get the tally warning this morning. See attached log. |
Not calling this as closed yet. Yes, there is a work-around in v4.0.32+, which makes it go away with a warning, but I am not happy with why it is happening at all. It should not be so. |
I'm fairly certain that the whole 'tally' thing is a thing of the past in v4.0.34, so closing this. I added a separate dictionary to hold the current tally, which will not be interfered with by a forecast get/retry sequence. |
The integration successfully makes API calls to solcast servers when HA is restarted. However, with the next call a couple of hours later I get errors. From the debug info it looks as if the API call is successful at first, but then later the integration produces an error "SOLCAST - unable to get sensor value 'tally' Traceback". See attached debug info.
I'm using 2 API keys at the same time, because I have 4 planes with different orientations.
Solcast Integration Version
I'm on version 4.0.31
Solcast_Debug.txt
The text was updated successfully, but these errors were encountered: