core: Script, that turns on an already running script, hangs until that script finished

The problem

Imagine the following scripts:

script_a:
  sequence:
  - delay:
      seconds: 0

script_b:
  sequence:
  - delay:
      seconds: 120

script_c:
  sequence:
  - delay:
      seconds: 0

script_d:
  sequence:
  - service: script.turn_on
    entity_id: script.script_a
  - service: script.turn_on
    entity_id: script.script_b
  - service: script.turn_on
    entity_id: script.script_c

If I just run script_d, then everything works as expected: all three “child” scripts are triggered and script_d finishes, script_a and script_c finish in a moment and script_b finishes in two minutes.

Now let’s run script_b first, wait for a few seconds and then run script_d. As expected, when script_d triggers script_b, nothing happens. because the script is already running:

2020-09-18 10:30:18 WARNING (MainThread) [homeassistant.components.script.script_b] script_b: Already running

But instead of continuing to the next step, script_d hangs and starts to wait until the previous run of script_b finished! See the log below.

Environment

Home Assistant Core release with the issue: 0.114.1
Last working Home Assistant Core release (if known): a few releases ago, I guess
Operating environment (OS/Container/Supervised/Core): Core in Virtualenv on Raspberry Pi
Integration causing this issue: Script
Link to integration documentation on our website: https://www.home-assistant.io/integrations/script/

Problem-relevant `configuration.yaml`

n/a

Traceback/Error logs

2020-09-18 10:30:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=script, service=turn_on, service_data=entity_id=script.script_b>
2020-09-18 10:30:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event script_started[L]: name=script_b, entity_id=script.script_b>
2020-09-18 10:30:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_b, old_state=<state script.script_b=off; last_triggered=None, mode=single, current=0, friendly_name=script_b @ 2020-09-18T10:24:56.064147+03:00>, new_state=<state script.script_b=on; last_triggered=2020-09-18T10:30:13.439877+03:00, mode=single, current=1, friendly_name=script_b @ 2020-09-18T10:30:13.440463+03:00>>
2020-09-18 10:30:13 INFO (MainThread) [homeassistant.components.script.script_b] script_b: Running script
2020-09-18 10:30:13 INFO (MainThread) [homeassistant.components.script.script_b] script_b: Executing step delay 0:02:00
2020-09-18 10:30:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_b, old_state=<state script.script_b=on; last_triggered=2020-09-18T10:30:13.439877+03:00, mode=single, current=1, friendly_name=script_b @ 2020-09-18T10:30:13.440463+03:00>, new_state=<state script.script_b=on; last_triggered=2020-09-18T10:30:13.439877+03:00, mode=single, current=1, last_action=delay 0:02:00, friendly_name=script_b @ 2020-09-18T10:30:13.440463+03:00>>

2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=script, service=turn_on, service_data=entity_id=script.script_d>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event script_started[L]: name=script_d, entity_id=script.script_d>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_d, old_state=<state script.script_d=off; last_triggered=None, mode=single, current=0, friendly_name=script_d @ 2020-09-18T10:24:56.065323+03:00>, new_state=<state script.script_d=on; last_triggered=2020-09-18T10:30:18.817164+03:00, mode=single, current=1, friendly_name=script_d @ 2020-09-18T10:30:18.817927+03:00>>
2020-09-18 10:30:18 INFO (MainThread) [homeassistant.components.script.script_d] script_d: Running script
2020-09-18 10:30:18 INFO (MainThread) [homeassistant.components.script.script_d] script_d: Executing step call service
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=script, service=turn_on, service_data=entity_id=['script.script_a']>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event script_started[L]: name=script_a, entity_id=script.script_a>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_a, old_state=<state script.script_a=off; last_triggered=None, mode=single, current=0, friendly_name=script_a @ 2020-09-18T10:24:56.063334+03:00>, new_state=<state script.script_a=on; last_triggered=2020-09-18T10:30:18.859116+03:00, mode=single, current=1, friendly_name=script_a @ 2020-09-18T10:30:18.859543+03:00>>
2020-09-18 10:30:18 INFO (MainThread) [homeassistant.components.script.script_a] script_a: Running script
2020-09-18 10:30:18 INFO (MainThread) [homeassistant.components.script.script_a] script_a: Executing step delay 0:00:00
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_a, old_state=<state script.script_a=on; last_triggered=2020-09-18T10:30:18.859116+03:00, mode=single, current=1, friendly_name=script_a @ 2020-09-18T10:30:18.859543+03:00>, new_state=<state script.script_a=on; last_triggered=2020-09-18T10:30:18.859116+03:00, mode=single, current=1, last_action=delay 0:00:00, friendly_name=script_a @ 2020-09-18T10:30:18.859543+03:00>>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_a, old_state=<state script.script_a=on; last_triggered=2020-09-18T10:30:18.859116+03:00, mode=single, current=1, last_action=delay 0:00:00, friendly_name=script_a @ 2020-09-18T10:30:18.859543+03:00>, new_state=<state script.script_a=off; last_triggered=2020-09-18T10:30:18.859116+03:00, mode=single, current=0, friendly_name=script_a @ 2020-09-18T10:30:18.879949+03:00>>
2020-09-18 10:30:18 INFO (MainThread) [homeassistant.components.script.script_d] script_d: Executing step call service
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=script, service=turn_on, service_data=entity_id=['script.script_b']>
2020-09-18 10:30:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event script_started[L]: name=script_b, entity_id=script.script_b>
2020-09-18 10:30:18 WARNING (MainThread) [homeassistant.components.script.script_b] script_b: Already running

2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_b, old_state=<state script.script_b=on; last_triggered=2020-09-18T10:30:13.439877+03:00, mode=single, current=1, last_action=delay 0:02:00, friendly_name=script_b @ 2020-09-18T10:30:13.440463+03:00>, new_state=<state script.script_b=off; last_triggered=2020-09-18T10:30:13.439877+03:00, mode=single, current=0, friendly_name=script_b @ 2020-09-18T10:32:13.453092+03:00>>
2020-09-18 10:32:13 INFO (MainThread) [homeassistant.components.script.script_d] script_d: Executing step call service
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=script, service=turn_on, service_data=entity_id=['script.script_c']>
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event script_started[L]: name=script_c, entity_id=script.script_c>
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_c, old_state=<state script.script_c=off; last_triggered=None, mode=single, current=0, friendly_name=script_c @ 2020-09-18T10:24:56.064752+03:00>, new_state=<state script.script_c=on; last_triggered=2020-09-18T10:32:13.485586+03:00, mode=single, current=1, friendly_name=script_c @ 2020-09-18T10:32:13.486171+03:00>>
2020-09-18 10:32:13 INFO (MainThread) [homeassistant.components.script.script_c] script_c: Running script
2020-09-18 10:32:13 INFO (MainThread) [homeassistant.components.script.script_c] script_c: Executing step delay 0:00:00
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_c, old_state=<state script.script_c=on; last_triggered=2020-09-18T10:32:13.485586+03:00, mode=single, current=1, friendly_name=script_c @ 2020-09-18T10:32:13.486171+03:00>, new_state=<state script.script_c=on; last_triggered=2020-09-18T10:32:13.485586+03:00, mode=single, current=1, last_action=delay 0:00:00, friendly_name=script_c @ 2020-09-18T10:32:13.486171+03:00>>
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_c, old_state=<state script.script_c=on; last_triggered=2020-09-18T10:32:13.485586+03:00, mode=single, current=1, last_action=delay 0:00:00, friendly_name=script_c @ 2020-09-18T10:32:13.486171+03:00>, new_state=<state script.script_c=off; last_triggered=2020-09-18T10:32:13.485586+03:00, mode=single, current=0, friendly_name=script_c @ 2020-09-18T10:32:13.551107+03:00>>
2020-09-18 10:32:13 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=script.script_d, old_state=<state script.script_d=on; last_triggered=2020-09-18T10:30:18.817164+03:00, mode=single, current=1, friendly_name=script_d @ 2020-09-18T10:30:18.817927+03:00>, new_state=<state script.script_d=off; last_triggered=2020-09-18T10:30:18.817164+03:00, mode=single, current=0, friendly_name=script_d @ 2020-09-18T10:32:13.554062+03:00>>