Automation caused "Task was destroyed but it is pending!"

Configuration
1

Hi,

when the automation below is executed, I get the error “Task was destroyed but it is pending!” in log. The automation is a few releases old, maybe there is a better way to do it? It worked without problems in the past but I guess something has changed with one of the last releases.

- id: 'Bell'
  alias: Bell
  description: ''
  trigger:
  - platform: state
    entity_id: binary_sensor.vibration
    from: 'off'
    to: 'on'
  condition:
  - condition: time
    after: '06:30:00'
    before: '22:30:00'
  action:
  - service: media_player.play_media
    data:
      entity_id: media_player.mpd
      media_content_id: http://IP/local/sounds/Bell.mp3
      media_content_type: 'music'
  - service: input_text.set_value
    entity_id: input_text.img_name
    data_template:
      value: "door_{{now ().day }}.{{ now ().month }}.{{ now ().year }}_{{ now ().hour }}_{{ now ().minute }}.jpg"
  - service: camera.snapshot
    alias: ''
    data:
      filename: /config/www/cam_captures/{{states('input_text.img_name')}}
    entity_id: all
  - service: notify.1
    data_template:
      title: ""
      message: ""
      data:
        path: /config/www/cam_captures/{{states('input_text.img_name')}}
  - service: light.turn_on
    entity_id: light.light_1
    data_template:
      hs_color:
        - 120
        - 100
      brightness: 255
      transition: 1
  - delay: 00:00:01
  - service: notify.2
    data_template:
      title: ""
      message: ""
      data:
        path: /config/www/cam_captures/{{states('input_text.img_name')}}
  - service: light.turn_on
    entity_id: light.light_1
    data_template:
      hs_color:
        - 240
        - 100
      brightness: 255
      transition: 1
  - delay: 00:00:01
  - service: notify.3
    data_template:
      title: ""
      message: ""
      data:
        path: /config/www/cam_captures/{{states('input_text.img_name')}}
  - service: light.turn_on
    entity_id: light.light_1
    data_template:
      hs_color:
        - 0
        - 100
      brightness: 255
      transition: 1
  - delay: 00:00:03
  - service: light.turn_on
    entity_id: light.light_1
    data_template:
      hs_color:
        - 44.941
        - 100
      brightness: 115
      transition: 0
  - delay: 00:00:01
  - service: light.turn_off
    entity_id: light.light_1
2

If you look in the log there should be INFO messages that show when each step of the action section is executed. It might help to take a look to see if there are any clues as to which step is causing the problem. I don’t see anything obvious. Depending on how you have logger configured you may need to make changes to see those messages. They won’t show up in the GUI by default. You either need to click the button to load the whole log, or look in the home-assistant.log file.

3

I set the logger on debug. The Automation was running at 8:36, at this time the error does not occur. 3 minutes later I get this:

2020-07-16 08:38:57 DEBUG (Recorder) [homeassistant.components.recorder] Sending keepalive
2020-07-16 08:39:01 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=sensor.time, old_state=<state sensor.time=08:38; friendly_name=Time, icon=mdi:clock @ 2020-07-16T08:38:01.003407+02:00>, new_state=<state sensor.time=08:39; friendly_name=Time, icon=mdi:clock @ 2020-07-16T08:39:01.005921+02:00>>
2020-07-16 08:39:03 DEBUG (SyncWorker_13) [mpd.base] Calling MPD status()
2020-07-16 08:39:03 DEBUG (SyncWorker_13) [mpd.base] Calling MPD currentsong()
2020-07-16 08:39:14 DEBUG (SyncWorker_1) [mpd.base] Calling MPD status()
2020-07-16 08:39:14 DEBUG (SyncWorker_1) [mpd.base] Calling MPD currentsong()
2020-07-16 08:39:19 DEBUG (MainThread) [pydeconz.websocket] {"attr":{"lastannounced":"2020-07-06T09:57:39Z","lastseen":"2020-07-16T06:39:19Z","manufacturername":"IKEA of Sweden","modelid":"TRADFRI bulb E14 CWS opal 600lm","name":"Licht 1","swversion":"1.3.009","type":"Color light","uniqueid":"00:0d:6f:ff:fe:46:4d:c2-01"},"e":"changed","id":"3","r":"lights","t":"event","uniqueid":"00:0d:6f:ff:fe:46:4d:c2-01"}
2020-07-16 08:39:24 DEBUG (SyncWorker_8) [mpd.base] Calling MPD status()
2020-07-16 08:39:24 ERROR (SyncWorker_10) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2020-07-16 08:39:24 DEBUG (SyncWorker_8) [mpd.base] Calling MPD currentsong()
2020-07-16 08:39:24 ERROR (SyncWorker_10) [homeassistant.core] Error doing job: Task was destroyed but it is pending!
2020-07-16 08:39:24 DEBUG (SyncWorker_10) [homeassistant.components.recorder.util] querying 1 rows took 0.005322s
2020-07-16 08:39:24 DEBUG (SyncWorker_10) [homeassistant.components.recorder.util] querying 0 rows took 0.003965s
2020-07-16 08:39:24 DEBUG (SyncWorker_10) [homeassistant.components.history] getting 1 first datapoints took 0.005578s
4

Hmm, that might be difficult to debug.

Are you sure these errors occur only due to that particular automation running? And do they always happen about the same amount of time after the automation runs?

Is it at all possible that binary_sensor.vibration changes quickly, such that it might re-trigger the automation while the actions are still running, e.g., on-off-on quickly?

5

This is highly likely. Would also explain why the light sometimes not turning off. Did not thought about that :blush:
How can I prevent that?

6

In the 0.113 release that is in beta right now the way automations & scripts work has changed significantly. Without any changes to your configuration, if the automation is re-triggered while the actions are still running the trigger will be ignored (and you’ll see a warning stating so.)

You’ll also have the choice of selecting a different behavior via the new mode config option. E.g., restart will cause the actions to stop and then start over if the automation is re-triggered while the actions are still running. Or you could select queued mode, in which case the actions will finish and then be run again.

7

That sound pretty good, 0.113 isn’t that far away and I can live with the issues till then.
What about the automation itself? Is the way of color changing still the way to go? :slight_smile:

8

As far as I know, yes. I do have dimmable lights, but not colored lights, so I’m not all that familiar with it.

9

Ok, thanks alot, waiting for 0.113 then :slight_smile:

1 Like
10

I have added mode: single to the automation but had the error again today. I have also added - delay: 00:00:10. The automation did run without any issues though. What else could cause that?

11

Even with 0.116.2 I have these errors…

12

I also have been seeing this error quite a bit recently but it’s only after a restart of HA I don’t see it any other time.

13

I also see it after every HA restart

14

I still see this after every restart

15

It is not automation that causes it on my installation it seems. I raised [homeassistant] Error doing job: Task was destroyed but it is pending! · Issue #50492 · home-assistant/core · GitHub

I am tired of seeing this error in the log

1 Like