home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.56k stars 30.74k forks source link

Trigger Update Coordinator: Running script requires passing in a context #99914

Closed hmmbob closed 7 months ago

hmmbob commented 1 year ago

The problem

With the deprecation of the forecast attribute, I've created a template sensor for the daily maximum temperature (see yaml below). Every hour, I get this warning in my logs, without any further information:

2023-09-08 12:00:00.222 WARNING (MainThread) [homeassistant.helpers.script.trigger_update_coordinator] Trigger Update Coordinator: Running script requires passing in a context

What version of Home Assistant Core has the issue?

core-2023.9.0

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Core

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

template:
  - trigger:
      - platform: time_pattern
        hours: "/1"
      - platform: homeassistant
        event: start
      - platform: event
        event_type: event_template_reloaded
    action:
      - service: weather.get_forecast
        data:
          type: daily
        target:
          entity_id: weather.knmi_home
        response_variable: forecast
    sensor:
      - name: KNMI max temp vandaag
        unique_id: knmi_max_temp_vandaag
        state: "{{ forecast.forecast[0].temperature }}"
        availability: "{{ is_number(forecast.forecast[0].temperature) }}"

Anything in the logs that might be useful for us?

2023-09-08 10:00:00.493 WARNING (MainThread) [homeassistant.helpers.script.trigger_update_coordinator] Trigger Update Coordinator: Running script requires passing in a context
2023-09-08 11:00:00.493 WARNING (MainThread) [homeassistant.helpers.script.trigger_update_coordinator] Trigger Update Coordinator: Running script requires passing in a context
2023-09-08 12:00:00.222 WARNING (MainThread) [homeassistant.helpers.script.trigger_update_coordinator] Trigger Update Coordinator: Running script requires passing in a context

Additional information

No response

home-assistant[bot] commented 1 year ago

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

Code owner commands Code owners of `template` 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 template` Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


template documentation template source (message by IssueLinks)

mbo18 commented 1 year ago

I have exactly the same log! Did not find why. All I did was modifying my template sensor using trigger and action to use the new forecast service

hmmbob commented 1 year ago

Still there on 2023.9.2

pedolsky commented 1 year ago

Same here using service: calendar.list_events.

My calendar sensor (similiar to service: weather.get_forecast ) is the only one with an hourly time pattern trigger. Since I created it, I receive an hourly error message as described above.

kds69 commented 1 year ago

still there with 2023.9.3

hmmbob commented 1 year ago

And still here on 2023.10.0b2

PaulBiod commented 1 year ago

same here, using the doc example

tommyjlong commented 1 year ago

Still there with 2023.10.0

doug-hoffman commented 1 year ago

This warning is generated in homeassistant/helpers/script.py:

    async def async_run(
        self,
        run_variables: _VarsType | None = None,
        context: Context | None = None,
        started_action: Callable[..., Any] | None = None,
    ) -> ScriptRunResult | None:
        """Run script."""
        if context is None:
            self._log(
                "Running script requires passing in a context", level=logging.WARNING
            )
            context = Context()

It appears the warning is unnecessary, or should only be logged at a more verbose level, since the lack of context is already being dealt with by creating an empty Context().

As a workaround, you can define an automation to generate a custom event for triggers that don't have context, then have the template sensor trigger from the custom event (which will have context):

automation:
  - alias: "Refresh 1h"
    trigger:
      - platform: homeassistant
        event: start
      - platform: time_pattern
        hours: "/1"
    action:
      - event: refresh_1h
template:
  - trigger:
      - platform: event
        event_type: refresh_1h
      - platform: event
        event_type: event_template_reloaded
    action:
      - service: weather.get_forecast
        data:
          type: daily
        target:
          entity_id: weather.knmi_home
        response_variable: forecast
    sensor:
      - name: KNMI max temp vandaag
        unique_id: knmi_max_temp_vandaag
        state: "{{ forecast.forecast[0].temperature }}"
        availability: "{{ is_number(forecast.forecast[0].temperature) }}"
hmmbob commented 1 year ago

Still here on 2023.11.0b0

hmmbob commented 11 months ago

Just a note to indicate it is still existing on 2023.12.0b1 (which makes sense because the PR hasn't been merged yet)

doug-hoffman commented 11 months ago

Unfortunately, I discovered that creating a new context within the template component makes the logbook inaccurate. For that reason, I'm leaving the PR as a draft until I have more time to get back to it or someone else finishes what I've started.

Creating a new context causes it to blame any change in the template sensors on the first service called in the action section, which is inaccurate. A fix I found for that is to also fire an event after we create a new context and define an async_describe_events callback to format/display the event in the logbook. Then every time any trigger fires we would spam an additional logbook entry that says nothing but 'template block was triggered', which is less than ideal, but prevents the logbook from associating the state change with the call_service event.

The context/logbook behavior isn't obviously documented and I'm not super familiar, so I'm having to make sense of it as I go. There may be a better way to solve the subsequent issues that isn't obvious to me.

erkr commented 11 months ago

Bump. Still in 2023.12 @doug-hoffman great you try to create a fix! To my understanding you want to add context inside the template integration. I think the issue is related to sun/time/date triggers are missing context. Related issue: https://github.com/home-assistant/core/issues/68047

hmmbob commented 10 months ago

And still existing on 2024.1.0b5 (so it also isn't fixed by anything else, is my point ;) )

erkr commented 10 months ago

I don't know the impact of providing a context for time/date/sun triggers, but just making the logging debug level would be fine for me as well (as it is working)

hpoperator86 commented 10 months ago

I have exactly the same problem which is spamming my log (thousands of listings within one day). However, it's a bit easier for me to determine the origin, as my system is up-to-date and virgin and I have only set up 2 automations so far. The error appears with every automation that I generate. Attached is the error that is displayed and the two automations I have running in HA (I don't think the automation that triggers the switch for the first time (activated) is responsible because this automation was installed when the error already appeared in the log file). Screenshot 2024-01-14 151710 Screenshot 2024-01-14 151742 Screenshot 2024-01-14 151804

erkr commented 10 months ago

Weird, I have these loggings only for automations triggered by time, date or sun triggers, where I call a script. But you are using device - power triggers, and you don't call a script either. Did you check that the trace timestamps of the automations Match with the loggings?

hpoperator86 commented 10 months ago

@erkr

Strange, I only have these logs for automations triggered by time, date or sun triggers where I call a script. But you are using device power triggers and not calling a script either. Have you checked that the trace timestamps of the automations match the logs?

yes, these match. or rather, another disruptive factor can also be ruled out because, as I mentioned, I have only installed two automations so far. One is the notification when the washing machine is ready and the pressing of the helper.button (Status_Waschmaschine). and on the other hand the automation which presses the created helper.button (Status_Waschmaschine) as soon as the smart power plug detects a power of 10 W.

It is really very strange that such warnings are displayed. I have already discussed this problem on HA's Discord server, under the Automations section, and here I got the answer that I can ignore this warning for the time being, as this is only a warning. Very strange statement. It was also not possible to determine what was causing the error

erkr commented 10 months ago

Automations are not the only source. I.e template sensors with time triggers, where the action calls a script will cause these warnings as well. I have over hundred automations that don't cause them. Please check if the warnings continue when you temporary disable these 2 automations

erkr commented 10 months ago

Example of a template binary sensor that causes these warnings:


- trigger:
  - platform: time
    at: "00:00:05"
  action:
    - service: pyscript.check_maintenance_actions
      data:
        dashboardUrl: dashboard-kiosk
        viewTitle: status
      response_variable: response
  binary_sensor:
  - unique_id: maintenance 
    name: Maintenance
    state: "{{ response.expired > 0 }}"
erkr commented 10 months ago

@hpoperator86 The warnings Are for calling a script without a context. Your automations don't call a script. So I really doubth they cause the warnings.

hmmbob commented 9 months ago

Just dropping a note to prevent this becoming stale, as it is still occurring on 2024.2.0b1

Mariusthvdb commented 8 months ago

even on todays dev install... 2024.3.0.dev20240216 using this trigger template: https://github.com/TheFes/cheapest-energy-hours/blob/main/documentation/1-source_sensor.md

is this even looked into?

Mariusthvdb commented 8 months ago

@hpoperator86 The warnings Are for calling a script without a context. Your automations don't call a script. So I really doubth they cause the warnings.

In my system, the warnings are only logged for trigger based templates that are using a service with a response variable. As in the opening post. has nothing to do with automations or scripts (although under the hood they may be related obviously)

TheFes commented 8 months ago

As far as I know automations will, in the background, call the action part as a script. The action sequence from a trigger based template sensor will be the same. So that will be why the error states a script is running

erkr commented 8 months ago

@TheFes I have my doubts if @hpoperator86 took the right conclusion as he assumed the loggings where the result of automations. As @Mariusthvdb mentioned, I also do see the loggings for time triggered template sensors only! If automations like the ones included above would be the cause, I should be spammed. That is not the case.

@hpoperator86 would be great if you can confirm the loggings are gone if you disable your two automations

Mariusthvdb commented 8 months ago

yes, and the trigger is important, because my weather template dos not throw the error when using:

template:

  - trigger:
      - platform: state
        entity_id: sensor.date
#       - platform: event
#         event_type: event_template_reloaded
#       - platform: homeassistant
#         event: start
    action:
      - service: weather.get_forecasts
        target:
          entity_id: weather.buienradar
        data:
          type: daily
        response_variable: buienradar_forecast

I only experienced the warning after installing this:

template:

  - trigger:
#       - platform: time_pattern
#         hours: '/1'
      - platform: homeassistant
        event: start
    action:
      - service: easyenergy.get_energy_usage_prices
        data:
          incl_vat: false
          config_entry: 382801d5dbf1bebc969f1fa7fb2e31c6
          start: >
            {{today_at() - timedelta(days=1)}}
          end: >
            {{today_at() + timedelta(days=2)}}
        response_variable: prices

with either (or all) trigger. So even homeassisant start triggers the warning, which would hardly constitute a 'timing' trigger.

2sheds commented 8 months ago

My setup is as follows and I also get these warnings:

template:
  - unique_id: homepod
    trigger:
      - platform: webhook
        webhook_id: "SECRET_HERE"
        allowed_methods:
          - POST
        local_only: true
    action:
      - service: input_boolean.turn_off
        target:
          entity_id: input_boolean.homepod_update

I have a time-based automation that turns input_boolean on to initiate the update and the template sensor above to capture the results. Disabling the automation and toggling the input manually results in the same warning.

While this is open, I changed the corresponding automation in HomeKit to turn off the input_boolean instead. When I remove the action, the warnings disappear.

erkr commented 8 months ago

Hi all

Accidentally I found out the "action" clause seems crucial (as suggested by @TheFes), when I refactored this sensor (no loggings):

# Template NOT causing  missing context loggings:
- trigger:
  - platform: time_pattern
    minutes: /5
  binary_sensor:
  - unique_id: check_windows
    name: Check windows
    state: |
        {%- from 'tools.jinja' import check_window %}
        {{ check_window()|bool }}
    device_class: problem

Into this variation with the action clause (causing context loggings):

# Template sensor causing the missing context logging (every 5 minutes):
- trigger:
  - platform: time_pattern
    minutes: /5
  action:
  - variables:
      status: |
        {%- from 'tools.jinja' import check_window %}
        {{ check_window()|bool }}
  binary_sensor:
  - unique_id: check_windows
    name: Check windows
    state: "{{ status }}"
    device_class: problem

Note: Functionally, these two versions are identical. But only the second one causes the loggings.

Best Eric

boheme61 commented 8 months ago

@jaydeethree You are right, Changing to the "trigger" as in your "solution" , doesn't throw errors On the other hand, it doesn't update either, as it seems the weather-integration doesn't make calls to the Provider-Api, when they update information ( Maybe the weather-integration only makes 1, at best 2 calls a day , to the cached data, from the i.e met.no integration) Below changes as in your "Fix" is not reliable, as in an hour the data is outdated, and not updated

template:
  - trigger:
      - platform: state
        entity_id: weather.home
    action:
      - service: weather.get_forecasts
        data:

On the other hand, yes the example in Weather-Integration page, does throw an error ( I have no idea how this example could end up in the Docs ) PS: i use met.no as provider

Im baffled about how a homeautomation system, can even "implement" such an unreliable weather-integration, since the "turnover" to service-call for weather. The default weather card, was previous announced that changes been made so the integration should provide 6 days instead of 5, but fact is , the card shows 5( Where As 1 is actually current, most of the hour, so it leaves us with 4 days forecast. in the default card, using met.no ) Forecast are as known "unreliable" therefore Providers updates there forecasts at-least every hour, cause i.e the Wind Changes, more rain than expected, colder doo to wind-change etc.

I Hope Devs will reconsider this Integration, as weather-forecast IS an Important feature in a homeautomation system, im pretty sure noone using HA haven't got the weather in their installation. Everyone has ! ( They rely upon it( as much as one can ) , but most are not ware about the actual "glitch" and unreliable facts, because they don't compare. But it seems like Devs forcing people into template-sensors, automations and own-made direct Api-calls , as currently one can not rely upon this implementation of a weather-forecast, to control anything. And the "still" constant " Trigger Update Coordinator: Running script requires passing in a context " even with the example in Docs, is unbelievable This is i assume, your suggested solution applied to Example in Docs, using met.no.

  - trigger:
      - platform: state
        entity_id: weather.forecast_home
    action:
      - service: weather.get_forecasts
        data:
          type: hourly
        target:
          entity_id: weather.forecast_home
        response_variable: hourly
    sensor:
      - name: Temperature forecast next hour
        unique_id: temperature_forecast_next_hour
        state: "{{ hourly['weather.forecast_home'].forecast[0].temperature }}"
        unit_of_measurement: °C

PS: i added " availability: "true" ", just for a test, also tried with the suggested " is_number " above ( However not in an automation ) , only for this example sensor

erkr commented 8 months ago

Please don't derail the issue to a weather sensor discussion. The documented sensor for that is just an example that causes context warning logs. And yes with a weather state trigger in stead of a time pattern is just a work around the issue:

Trigger based template sensors with particular triggers, like time, date, sun..., and an action section in the template, cause these loggings.

I hope that this gets resolved, as for other template sensors, there is no easy work around.

boheme61 commented 8 months ago

True, however The orig Issue here is reported on the weather, so it's a good place to start fixing it, if it's not possible with a "global" fix Edit: The "workaround" is as mentioned , Not Optimal (the logs could have been hided in logger-level) but "random/late" updates, is not much to rely upon PS: A common thing here seems to be " a service-call " ( I have not tested ! )

jaydeethree commented 8 months ago

Please don't derail the issue to a weather sensor discussion

I agree. I mentioned this issue in my PR because the example in the Home Assistant weather docs is one case where this can occur, but changing the weather docs won't fix the actual problem here.

You are right, Changing to the "trigger" as in your "solution" , doesn't throw errors On the other hand, it doesn't update either, as it seems the weather-integration doesn't make calls to the Provider-Api, when they update information

I've been using my example for several days and it has been working perfectly for me. To avoid derailing this issue though, please move discussion about this to my PR.

erkr commented 8 months ago

PS: A common thing here seems to be " a service-call " ( I have not tested ! )

No, I tested. A triggered template with an action: section and particular triggers is enough. I am calling a template macro that's just testing entity states, and have these warnings as well.

teskanoo commented 8 months ago

I may be missing something here, but I would assume that if a trigger condition is met, then that trigger condition would become the event context.

In the example from doug-hoffman, it seems that the event context would be the Automation (automation.refresh_1h)

automation:
  - alias: "Refresh 1h"
    trigger:
      - platform: homeassistant
        event: start
      - platform: time_pattern
        hours: "/1"
    action:
      - event: refresh_1h

In the following example it seems that the event context would be the template trigger itself (either the time_pattern or the homeassistant start event)

template:

  - trigger:
       - platform: time_pattern
         hours: '/1'
      - platform: homeassistant
        event: start
akloeckner commented 8 months ago

I think the issue is simply: Not all triggers have a context (yet). 🤷 That might be by design, because not all triggers are tied to an actual event (which seems to be the rule when to generate a new context). The issue does not appear with automations, because the automation generates its own event "automation_triggered" (thus creating a new context for its actions).

The solution would be to either

Core developers might ask to also generate an event in both of these cases.

akloeckner commented 8 months ago

After some discussion in a different context, I believe that creating a new context would be correct. That is done for automations, because the automation action should not run with limited permissions of the user causing it to trigger. The same holds for the actions in a template sensor, I'd argue. And for automations, an event is fired explicitly for it to serve as "the cause" for any changes resulting from an automation. So, the template should fire an event, too.

doug-hoffman commented 8 months ago

After some discussion in a different context, I believe that creating a new context would be correct. That is done for automations, because the automation action should not run with limited permissions of the user causing it to trigger. The same holds for the actions in a template sensor, I'd argue. And for automations, an event is fired explicitly for it to serve as "the cause" for any changes resulting from an automation. So, the template should fire an event, too.

I started to go down this path in #102975, but haven't had time to finish it.

I suspect any change would benefit from some architectural discussion to nail down exactly how it should be implemented. Even though it seems like the right way based on what automations do, templates differ slightly from automations and will require a slightly different approach. Unlike automations, template blocks don't have a direct name or entity ID, or a 1:1 relationship with an entity, so events end up being "A template block was triggered." Mostly useless on its own.

A few events are hidden from the logbook, so it may be possible to expand that list to include the new event. This would prevent spamming useless information in the frontend and still allow blame to be assigned in the subsequent event fired any time a trigger results in template sensors experiencing a state change.

It would be possible to include an attribute with the entity IDs of all template sensors that were affected by the trigger, but I don't recall the logbook being set up to handle a single event referencing multiple entities. This attribute could be used for triggering an automation based on when the template triggered event fires for specific entity IDs. (But this, too, seems mostly useless.)

By this point in my efforts, I began to suspect this process would be somewhat complex and realized I may not have the time to continue pursuing what originally seemed like such a simple fix. My workaround is still keeping this issue low on my list and I've still not got much time I'm willing to part with these days, so feel free to pick up where I left off.

akloeckner commented 8 months ago

Thanks for the wrap-up! Unfortunately, this sounds like out of my range, too... I'll try your workaround. Maybe it'll work for me as well. 👍

Update: It did. Thanks!

duczz commented 8 months ago

im using this code and get the same error:

#Advanced Heating Control
trigger:
  - platform: time_pattern
    minutes: /5
action:
  - service: calendar.get_events
    data:
      start_date_time: "{{ now() }}"
      end_date_time: "{{ now() + timedelta(minutes = 10) }}"
    target:
      entity_id:
        - calendar.xxxxxx_googlemail_com
        - calendar.feiertage
    response_variable: termine
allenporter commented 7 months ago

I'm able to reproduce this in my home system and will look for a fix

erkr commented 7 months ago

@allenporter My warnings are gone n 2024.3.3 THX :-)

allenporter commented 7 months ago

Thanks to @emontnemery who did the sleuthing!