Automation and Script Debugging?

Does anyone else find that automation traces sometimes don’t work, giving a “Chosen trace is no longer available” error message?

Also, how do you enable Script debugging in YAML mode? I can’t find anything in the Scripts Documentation page about it, and I’ve tried adding “id:” to a script without much luck.

I have an automation that is configured with an “id” to enable traces to be recorded. More often than not, when I click on “Show trace” in the Logbook, it tells me that the trace is no longer available. Yet that same automation has previously shown me a trace without issues, and will again sometimes work afterwards.

It’s not just one automation either, it happens with others with no particular pattern as to which one will fail to collect a trace.

Is there any debugging I can enable to find out why the traces sometimes don’t work?

Just in case it helps, one of the automations looks like this:

  - alias: Bed3 Bedside Night Light Button
    id: bed3_bedside_nightlight_button
    initial_state: 'on'
    trigger:
      platform: state
      entity_id: sensor.xiaomi_switch_sw10_action
    action:
      - choose:
          - conditions: "{{ trigger.to_state.attributes.action == 'single' }}"
            sequence:
              - service: script.opple_bed3_2_hold
          - conditions: "{{ trigger.to_state.attributes.action == 'double' }}"
            sequence:
              - service: script.opple_bed3_1_double
          - conditions: "{{ trigger.to_state.attributes.action == 'hold' }}"
            sequence:
              - service: script.opple_bed3_1_hold

No need for an id for scripts. They are already unique, as scripts are key/value pairs

script:
   script_name: # <--- unique ID

So traces should be available.

ah, that’s interesting. Should the logbook have a clickable “show trace” link next to each script entry? As seen in the screenshot below, I don’t see any trace option. (I’m running 2021.11.2)

Also, another example where the trace results in a “Chosen trace is no longer available” error message when I try to look at the " Aqara Opple kitchen Room" automation.

Only 5 traces are stored, everything past that is deleted.

That link might just be wrong if it’s a script. If it is a script, its going to the automations not scripts.

Hi @petro, thanks for your help. Keeping only 5 traces would make sense - would this count include subsequent script traces, or is it 5 automations and 5 script traces that are kept?

Do you know if there’s an automation size limit for traces? The example below has many conditions which doesn’t seem to work with a trace.

I also noticed that I can see script traces via Configuration → Scripts → ‘Debug script’ icon next to a script, but the “show trace” link never shows up in the logbook next to a script entry. Does this happen for you too?

I’ve had this automation for over a year now so the code/method is probably out of date.

  - alias: "Aqara Opple kitchen Room"
    id: aqara_opple_kitchen_room
    initial_state: 'on'
    trigger:
    - platform: mqtt
      topic: 'zigbee2mqttcc1352/switch_opple_kitchen'
    condition:
      condition: or
      conditions:
        - condition: template
          value_template: "{{ 'button_1_single' == trigger.payload_json.action }}" # bottom-left
        - condition: template
          value_template: "{{ 'button_1_hold' == trigger.payload_json.action }}" # bottom-left
        - condition: template
          value_template: "{{ 'button_2_single' == trigger.payload_json.action }}" # top-left
        - condition: template
          value_template: "{{ 'button_2_hold' == trigger.payload_json.action }}" # top-left
        - condition: template
          value_template: "{{ 'button_3_single' == trigger.payload_json.action }}" # bottom-middle
        - condition: template
          value_template: "{{ 'button_3_double' == trigger.payload_json.action }}" # bottom-middle
        - condition: template
          value_template: "{{ 'button_3_triple' == trigger.payload_json.action }}" # bottom-middle
        - condition: template
          value_template: "{{ 'button_3_hold' == trigger.payload_json.action }}" # bottom-middle
        - condition: template
          value_template: "{{ 'button_4_single' == trigger.payload_json.action }}" # top-middle
        - condition: template
          value_template: "{{ 'button_4_double' == trigger.payload_json.action }}" # top-middle
        - condition: template
          value_template: "{{ 'button_4_triple' == trigger.payload_json.action }}" # top-middle
        - condition: template
          value_template: "{{ 'button_4_hold' == trigger.payload_json.action }}" # top-middle
        - condition: template
          value_template: "{{ 'button_5_single' == trigger.payload_json.action }}" # bottom-right
        - condition: template
          value_template: "{{ 'button_5_double' == trigger.payload_json.action }}" # bottom-right
        - condition: template
          value_template: "{{ 'button_5_triple' == trigger.payload_json.action }}" # bottom-right
        - condition: template
          value_template: "{{ 'button_5_hold' == trigger.payload_json.action }}" # bottom-right
        - condition: template
          value_template: "{{ 'button_6_single' == trigger.payload_json.action }}" # top-right
        - condition: template
          value_template: "{{ 'button_6_double' == trigger.payload_json.action }}" # top-right
        - condition: template
          value_template: "{{ 'button_6_triple' == trigger.payload_json.action }}" # top-right
        - condition: template
          value_template: "{{ 'button_6_hold' == trigger.payload_json.action }}" # top-right
    action:
    - service: script.turn_on
      data_template:
        entity_id: >-
          {%- set script_map = {
                'button_1_single':'script.opple_kitchen_1_single',
                  'button_1_hold':'script.opple_kitchen_1_hold',
                'button_2_single':'script.opple_kitchen_2_single',
                  'button_2_hold':'script.opple_kitchen_2_hold',
                'button_3_single':'script.opple_kitchen_3_single',
                'button_3_double':'script.opple_kitchen_3_double',
                'button_3_triple':'script.opple_kitchen_3_triple',
                  'button_3_hold':'script.opple_kitchen_3_hold',
                'button_4_single':'script.opple_kitchen_4_single',
                'button_4_double':'script.opple_kitchen_4_double',
                'button_4_triple':'script.opple_kitchen_4_triple',
                  'button_4_hold':'script.opple_kitchen_4_hold',
                'button_5_single':'script.opple_kitchen_5_single',
                'button_5_double':'script.opple_kitchen_5_double',
                'button_5_triple':'script.opple_kitchen_5_triple',
                  'button_5_hold':'script.opple_kitchen_5_hold',
                'button_6_single':'script.opple_kitchen_6_single',
                'button_6_double':'script.opple_kitchen_6_double',
                'button_6_triple':'script.opple_kitchen_6_triple',
                  'button_6_hold':'script.opple_kitchen_6_hold'} -%}
          {{ script_map[trigger.payload_json.action] }}

no there isn’t

5 traces per entity. I.e. 5 traces for each automation, 5 traces for each script.

I limit my logbook, but this is probably coming. Traces in scripts is rather new.

That automation is fine, it’s a little verbose but it should have no problem in traces.

This automation is alittle different than yours but it’s easier to debug in the trace window. If you put all your templates into a variable section, you can see what’s failing. You can even use variables as a ‘configuration’ for your automation by just using yaml. In this, I made a config for your actions so that you can easily add or remove an action. Then all you need to do is add or remove the paired script. No jinja modification required.

  - alias: "Aqara Opple kitchen Room"
    id: aqara_opple_kitchen_room
    initial_state: 'on'
    trigger:
    - platform: mqtt
      topic: 'zigbee2mqttcc1352/switch_opple_kitchen'
    variables:
      config:
        button_1:
        - single
        - hold
        button_2:
        - single
        - hold
        button_3:
        - single
        - double
        - triple
        button_4:
        - single
        - double
        - triple
        - hold
        button_5:
        - single
        - double
        - triple
        - hold
        button_6:
        - single
        - double
        - triple
        - hold
      event: >
        {{ trigger.payload_json.action | default('button_0_invalid') }}
      items: >
        {{ event.split('_') }}
      button:
        {{ items[-2] }}
      action: >
        {{ items[-1] }}
      continue: >
        {{ config.get('button_' ~ button, {}).get(action) is not none }}
      service: >
        script.opple_kitchen_{{ button }}_{{ config['button_' ~ button][action] if continue else '' }}
    condition:
    - condition: template
      value_template: "{{ continue }}"
    action:
    - service: "{{ service }}"
1 Like

That’s an awesome automation, thank you for giving a great example! I never thought variables could be used that way, let alone figure out how to implement it as well as what you’ve done. :+1:
Most of my light switches use the Aqara Opple devices so this will drastically reduce my code - thanks!

Ah, I didn’t realise it was 5 per entity, I thought it was 5 traces across all entities - that’s really good to know, thank you!

I’ve been looking into this a bit more and discovered that the “show trace” link in the logbook is at fault here:

If I find the trace via Configuration → Automations → (search for automation) → Debug Icon, the trace for that automation does actually work!

What’s more interesting is that the “show trace” link actually points to the “opple_kitchen_1_single” script name, but the URL path is an automation trace. This would explain why I see the “Chosen trace is no longer available” error message.

The Logbook “show trace” link looks like this:
http://<my IP>:8123/config/automation/trace/opple_kitchen_1_single?run_id=2a05b1489387bbf10fac174edea2eceb

‘Configuration → Automations → Debug Icon’ URL looks like this:
http://<my IP>:8123/config/automation/trace/aqara_opple_kitchen_room

The actual script trace path should look like this:
http://<my IP>:8123/config/script/trace/script.opple_kitchen_1_single

So, there’s bug here that tries to link to a script trace when it should be an automation trace. Does anyone else see this as well or is it just me?

Write that issue up on github then and provide all that information.

Will do, thanks! I’m going to try and capture a different automation example to the Opple ones to see if it affects others too.

I don’t want to trouble you too much, but I’ve tried your automation example above and it unfortunately doesn’t seem to work.

The trace looks like this:

Changed variables has the following content:

this:
  entity_id: automation.aqara_opple_kitchen_room
  state: 'on'
  attributes:
    last_triggered: '2021-12-02T11:48:58.081092+00:00'
    mode: single
    current: 0
    id: aqara_opple_kitchen_room
    friendly_name: Aqara Opple kitchen Room
  last_changed: '2021-12-02T12:25:46.660537+00:00'
  last_updated: '2021-12-02T12:25:46.660537+00:00'
  context:
    id: 3c446d7eba6b469aba2c5ded278eff7c
    parent_id: null
    user_id: null
trigger:
  id: '0'
  idx: '0'
  platform: mqtt
  topic: zigbee2mqttcc1352/switch_opple_kitchen
  payload: >-
    {"action":"","battery":100,"last_seen":"2021-12-02T12:38:05.818Z","linkquality":39,"operation_mode":null,"voltage":3049}
  qos: 0
  description: mqtt topic zigbee2mqttcc1352/switch_opple_kitchen
  payload_json:
    action: ''
    battery: 100
    last_seen: '2021-12-02T12:38:05.818Z'
    linkquality: 39
    operation_mode: null
    voltage: 3049
config:
  button_1:
    - single
    - hold
  button_2:
    - single
    - hold
  button_3:
    - single
    - double
    - triple
  button_4:
    - single
    - double
    - triple
    - hold
  button_5:
    - single
    - double
    - triple
    - hold
  button_6:
    - single
    - double
    - triple
    - hold
event: ''
items:
  - ''
button: ''
action: ''
continue: false
service: script.opple_kitchen__

Is it because payload_json -> action doesn’t contain any value? Then again, I just pressed another Opple switch using the old automation and that had no value within Action either, yet it did successfully turn the lights on.

If it helps, MQTT Explorer does show that action is being populated:

the payload action was empty, it’s working as intended.

is there another trace before it? I’m assuming that it’s an event stream and it sends 2 events. 1 with the event, and 1 with it cleared. So check the previous trace.

i don’t care, i’m here to help

2 Likes

That’s a good point - I can see two events are fired:
image

However the first one has no trace details:

And the second one is the same as the previous post:

This is reflected in MQTT Explorer too:

The logbook only shows this though:
image

So for some reason it’s not picking up the first action containing “button_1_single”.

post the full changed variables

Unfortunately the first trace has no changed variables or any trace details:

The second trace is as above, where action is empty.

this:
  entity_id: automation.aqara_opple_kitchen_room
  state: 'on'
  attributes:
    last_triggered: '2021-12-02T11:48:58.081092+00:00'
    mode: single
    current: 0
    id: aqara_opple_kitchen_room
    friendly_name: Aqara Opple kitchen Room
  last_changed: '2021-12-02T12:25:46.660537+00:00'
  last_updated: '2021-12-02T12:25:46.660537+00:00'
  context:
    id: 3c446d7eba6b469aba2c5ded278eff7c
    parent_id: null
    user_id: null
trigger:
  id: '0'
  idx: '0'
  platform: mqtt
  topic: zigbee2mqttcc1352/switch_opple_kitchen
  payload: >-
    {"action":"","battery":100,"last_seen":"2021-12-02T13:00:15.196Z","linkquality":57,"operation_mode":null,"voltage":3049}
  qos: 0
  description: mqtt topic zigbee2mqttcc1352/switch_opple_kitchen
  payload_json:
    action: ''
    battery: 100
    last_seen: '2021-12-02T13:00:15.196Z'
    linkquality: 57
    operation_mode: null
    voltage: 3049
config:
  button_1:
    - single
    - hold
  button_2:
    - single
    - hold
  button_3:
    - single
    - double
    - triple
  button_4:
    - single
    - double
    - triple
    - hold
  button_5:
    - single
    - double
    - triple
    - hold
  button_6:
    - single
    - double
    - triple
    - hold
event: ''
items:
  - ''
button: ''
action: ''
continue: false
service: script.opple_kitchen__

Are there errors in the logs?

:man_facepalming: I should have thought to look there as well!

2021-12-02 13:00:15 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: 'list object' has no attribute 'get' when rendering '{{ config.get('button_' ~ button, {}).get(action) is not none }}'
2021-12-02 13:00:15 ERROR (MainThread) [homeassistant.components.automation.aqara_opple_kitchen_room] Error rendering variables: UndefinedError: 'list object' has no attribute 'get'
2021-12-02 13:00:15 WARNING (MainThread) [homeassistant.helpers.template] Template variable warning: homeassistant.helpers.template.Wrapper object has no element -2 when rendering '{{ items[-2] }}'

ah yep, a mistake

  - alias: "Aqara Opple kitchen Room"
    id: aqara_opple_kitchen_room
    initial_state: 'on'
    trigger:
    - platform: mqtt
      topic: 'zigbee2mqttcc1352/switch_opple_kitchen'
    variables:
      config:
        button_1:
        - single
        - hold
        button_2:
        - single
        - hold
        button_3:
        - single
        - double
        - triple
        button_4:
        - single
        - double
        - triple
        - hold
        button_5:
        - single
        - double
        - triple
        - hold
        button_6:
        - single
        - double
        - triple
        - hold
      event: >
        {{ trigger.payload_json.action or 'button_0_invalid' }}
      items: >
        {{ event.split('_') }}
      button: >
        {{ items[-2] }}
      action: >
        {{ items[-1] }}
      continue: >
        {{ action in config.get('button_' ~ button, []) }}
      service: >
        script.opple_kitchen_{{ button }}_{{ action }}
    condition:
    - condition: template
      value_template: "{{ continue }}"
    action:
    - service: "{{ service }}"

Works a treat now, thank you very much!!

Also, looking at the Changed Variables within the automation trace helps me understand your very clever use of variables.

event: button_1_single
items:
  - button
  - '1'
  - single
button: 1
action: single
continue: true
service: script.opple_kitchen_1_single

Just a heads up, the button variable in your example is missing the >

I’ve learned a lot today, thanks for your help @petro!

1 Like

Plus, even with this very different automation, the show trace link still points to the script rather than the automation: