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

History API not returning data from a specific time range when recorder runs are lost. Extending end time works #117793

Closed
tanelvakker opened this issue May 20, 2024 · 13 comments

Comments

@tanelvakker
Copy link

The problem

I use emhass to automate energy usage. Emhass queries past power usage using /api/history/period/ endpoint. About once a month it fails to retrieve data from a specific time range. After a day or so the issue mitigates automatically. I have narrowed it down to something to do with end_time. By default it's start + 1 day.
I am getting a 200 OK response, but body is "[]" when it does not work.
https://HA:8123/api/history/period/2024-05-18T15:56:00+00:00?filter_entity_id=sensor.load_power does not work
https://HA:8123/api/history/period/2024-05-18T15:56:00+00:00?filter_entity_id=sensor.load_power&end_time=2024-05-19T18:56:00 also does not work
Extending it by 1 minute to https://HA:8123/api/history/period/2024-05-18T15:56:00+00:00?filter_entity_id=sensor.load_power&end_time=2024-05-19T18:57:00 returns data just fine.

I suspect the code path it takes is https://github.com/home-assistant/core/blob/7998f874c09afc0d0537279d92aefb92da6fc573/homeassistant/components/history/__init__.py#L110C31-L110C53

Is there a way to check recorder_runs_manager.first.start manually?

How can I troubleshoot this further?

What version of Home Assistant Core has the issue?

2024.5.4

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

history

Link to integration documentation on our website

https://www.home-assistant.io/integrations/history/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

@home-assistant
Copy link

Hey there @home-assistant/core, mind taking a look at this issue as it has been labeled with an integration (history) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of history can trigger bot actions by commenting:

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

(message by CodeOwnersMention)


history documentation
history source
(message by IssueLinks)

@tanelvakker
Copy link
Author

I copied the history component over as a custom component and added logger to it.

            _LOGGER.info(f"history returning empty for entity_ids: {entity_ids} {get_instance(hass).recorder_runs_manager.first.start}")

which produces following log line:
2024-05-20 18:26:54.129 INFO (MainThread) [custom_components.history] history returning empty for entity_ids: ['sensor.load_power'] 2024-05-19 15:56:03.193007

@tanelvakker
Copy link
Author

image
this is what is in the recorder runs database. the question is why are previous runs missing from it?

@werdnum
Copy link

werdnum commented Aug 5, 2024

I'm experiencing this as well.

The history appears in the UI, but it doesn't appear in the API.

There's also something quite strange about the behaviour:

$ curl -fsSL https://homeassistant.andrewgarrett.dev/api/history/period/2024-08-02T12:47:00.000Z\?filter_entity_id\=sensor.powerpal_power -H "Authorization: Bearer $(yq -r .long_lived_token ~/workspace/emhass/secrets_emhass.yaml)" | jq '.[]|length'
1077

$ curl -fsSL https://homeassistant.andrewgarrett.dev/api/history/period/2024-08-02T12:46:00.000Z\?filter_entity_id\=sensor.powerpal_power -H "Authorization: Bearer $(yq -r .long_lived_token ~/workspace/emhass/secrets_emhass.yaml)" | jq '.[]|length'
0

In particular, the first timestamp reported by the second (working) request, should be included in the first request (which returns nothing), but it isn't.

$ curl -fSsL https://homeassistant.andrewgarrett.dev/api/history/period/2024-08-02T12:47:00.000Z\?filter_entity_id\=sensor.powerpal_power -H "Authorization: Bearer $(yq -r .long_lived_token ~/workspace/emhass/secrets_emhass.yaml)" | jq '[.[]|.[]|.last_reported]|min'
"2024-08-02T12:47:04.561857+00:00"

@danilotorrisi
Copy link

I'm having the exact same issue, is there any known workaround?

@tanelvakker
Copy link
Author

I copied https://github.com/home-assistant/core/tree/dev/homeassistant/components/history to config/custom_components and commented out


line 109-117
@bdraco can you suggest a better workaround?

@bdraco
Copy link
Member

bdraco commented Aug 9, 2024

Sounds like you have identified where the problem is. Any chance you could open a PR to fix it? My backlog is quite large right now so it could be a while before I can investigate.

@tanelvakker
Copy link
Author

Created a PR #123449

@bdraco
Copy link
Member

bdraco commented Aug 9, 2024

Thanks. Added a review comment to get the process started

@bdraco bdraco changed the title History API not returning data from a specific time range. Extending end time works History API not returning data from a specific time range when recorder runs are lost. Extending end time works Aug 9, 2024
@bdraco bdraco added the no-stale label Aug 9, 2024
@RudolfRendier
Copy link

RudolfRendier commented Nov 5, 2024

I have a similar issue with EMHASS in the days after Home Assistant restarts/upgrades.
My HA backup dates from November 3rd, 10:47 CET and I cannot get any values from the history API unless I provide an end-time that is a few minutes past this date, i.e.

This works:

"end_time": "2024-11-03T10:56:00+01:00",

This doesn't:

"end_time": "2024-11-03T10:55:00+01:00",

In the database this is the only recorder_run:

run_id start end closed_incorrect created
341 2024-11-03 09:55:53.823302   0 2024-11-03 09:55:53.846205

For example when trying to get the values from the first days of November:

import requests

url = my_domain + ":8123/api/history/period/2024-11-01"
headers = {
    "Authorization": "Bearer " + my_token,
    "Content-Type": "application/json"
}
params = {
    "end_time": "2024-11-03T10:56:00+01:00",
    "filter_entity_id": "sensor.power_load_no_var_loads",
    "significant_changes_only": "true",
    "minimal_response": "true",
    "no_attributes": "anything_goes"
}
response = requests.get(url, headers=headers, params=params)

print(response.json())

Looks like the purge cleans up all previous recorder_runs if they started before the purge period?
I think it should check when they ended, if that's within the purge-period, it should keep them?


def delete_recorder_runs_rows(
    purge_before: datetime, current_run_id: int
) -> StatementLambdaElement:
    """Delete recorder_runs rows."""
    return lambda_stmt(
        lambda: delete(RecorderRuns)
        .filter(RecorderRuns.start < purge_before)
        .filter(RecorderRuns.run_id != current_run_id)
        .execution_options(synchronize_session=False)
    )

My runs are typically about a month long, the start will be well outside of the purge period when it the run is ended due to a restart. The next purge will then delete it.

@emontnemery
Copy link
Contributor

emontnemery commented Nov 28, 2024

This should be fixed by #131702 which will be included in Home Assistant Core 2024.12.0b2

@tanelvakker @RudolfRendier can you verify you now get all data in the history queries, maybe once 2024.12.0b2 is available if you don't want to test on dev

@tanelvakker
Copy link
Author

This only happened about once per month of not restarting. I have also increased the recorder purge_keep_days to 30, which should also make it even harder to reproduce

@emontnemery
Copy link
Contributor

OK, I'm closing this issue then. Please open a new issue if it happens again.

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

Successfully merging a pull request may close this issue.

6 participants