Templating Problem (?)

I am stuck with (possibly) a templating problem. But I’m not even sure about that anymore…

From the beginning: I have a Denon AVR with 2 zone that are configured as 2 media player instances. Now when I power on zone 2, I want to get the source setting from zone 1 and apply it also to zone 2. Does not sound that complicated. Here is my automation for that:

  trigger:
  - entity_id: media_player.denon_terrasse
    from: 'off'
    platform: state
  condition:
  - condition: or
    conditions:
    - condition: state
      entity_id: media_player.denon_wohnzimmer
      state: 'on'
    - condition: state
      entity_id: media_player.denon_wohnzimmer
      state: playing
    - condition: state
      entity_id: media_player.denon_wohnzimmer
      state: paused
  action:
  -  service: media_player.select_source
     data_template:
       entity_id: media_player.denon_terrasse
       source: "{{ state_attr('media_player.denon_wohnzimmer', 'source') }}"

This is all fine, but some how the service call does not change the source on the target device if and only if the source to change to is AUX1. I can not figure out why that is. Switching the source to AUX1 via the Developer Tools works fine either by sending a service call or by the “Info Box” in the States tab. Even the resulting event calls in the log are identical (apart from the sequence the data items appear in.

Developer Tools Services:

2020-01-10 13:34:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=media_player, service=select_source, service_data=entity_id=media_player.denon_terrasse, source=AUX1>

Developer Tools States:

2020-01-10 14:24:51 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=media_player, service=select_source, service_data=source=AUX1, entity_id=media_player.denon_terrasse>

My automation:

2020-01-10 13:56:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=media_player, service=select_source, service_data=entity_id=media_player.denon_terrasse, source=AUX1>

The first two switch the source to AUX1 the last one doesn’t. All other sources apart from AUX1 work fine in the automation. Any hint is appreciated.

My guess (it is just a guess, because I don’t use any media_player devices) is that the automation is trying to switch the source too soon after it has turned on. Maybe add a delay before the service call.

That is not the case. Why would all the other sources work then. Apart from that the behavior is the same if the zone is already on and I trigger the automation by hand.

All good points. I can’t tell you. Clearly, based on your log snippets above, the service calls are the same. The first and third are even completely identical (which seems to rule out typos.) Which is what led me to suspect timing.

Yes, this would tend to imply timing isn’t the issue either.

Are there no errors or warnings in the log? Have you tried maybe enabling debug output?

What you see in the original post is (from) the debug output. It is silently taken by HA no additional hints on something going wrong in the logs. I’m not familiar enough with the internal implementation of service calls in HA to say what the difference might be. For sure it is something not obvious may be caused by the contents of the String handed over. I also don’t know whether the mere fact that the service is called with the same parameters in HA is indication enough that the processing is done in the same control flow.

In my experience, if the service call parameters are the same between two calls, no matter who or where the calls were made, they are processed the same. That’s kind of the point to the basic architecture of HA. Which tends to indicate state and/or timing issues if one call works and the other doesn’t.

Exactly how did you enable the debug output? I.e., what is your logger config? Also, what media_player integration are you using here (or what integration led to the creation of the media_player entities)? I could take a look at the code. Even if I can’t immediately see anything obvious I might be able to suggest a way to configure logger to get additional hints (such as enabling debug for the pypi.org package(s) in play.)

I would suggest you just add a small delay to test (it will take you less than 10 minutes an means we can eliminate that from the ‘possibles’

- delay: '00:00:05'
- service: media_player.select_source
  data_template:
    entity_id: media_player.denon_terrasse
    source: "{{ state_attr('media_player.denon_wohnzimmer', 'source') }}"

I was running on logger default level set to debug. The integration is denonavr. I’m suspecting a problem in the templating because even though the string “looks” the same as it might not be the same in the end. I also tried to nail the value for the source attribute down to “AUX1” not using the template and guess what. That also works fine. Unfortunately I did not make a copy of the log for that call, but I’m pretty sure it looked exactly the same as the other 3. I also tried feeding the output of the template to a persistent notification in parallel and that (no surprise) works just fine as well. That’s why I suspect the string that drops out of the template is not the same as from anywhere else. Still I don’t have an idea why this only trigger a problem for this one specific string.

Then maybe try:

       source: "{{ state_attr('media_player.denon_wohnzimmer', 'source').strip() }}"

EDIT: Or, when media_player.denon_wohnzimmer's source is AUX1, try this in the Template Editor:

<{{ state_attr('media_player.denon_wohnzimmer', 'source') }}>

Might give you some clues.

What underlying problem do you have in mind that only triggers with this very combination of template and string and can be solved by a delay?

A delay does not make a difference.

You have tried the delay and are confirming that it has made no difference ?

I’ve seen others here running AV equipment where they have to power something wait 1 minute 20 secs, set volume, wait 5 secs, select source, wait 5 secs, set mode to play.

Ive seen this on yamaha, denon, sonos and logitech hardware. Different delays for different things, they all had to set long delays and whittle them down until it becomes flakey then back step.

Messages sometimes have to propagate and if they arrive too quickly some get discarded.
I know that you feel that if you do it for zone 1 zone 2 should be the same but what if their logic was that all zone 2 messages should be delayed to give zone 1 a priority?
I don’t know, I’m just guessing based on what I’ve read

How would that be effected by the contents of the string?

Nope. Canyou point me to the implementation of

state_attr()

the stripping (how is that implemented?) does not make a difference.

state_attr() simply returns the specified attribute if the entity exists and it has that attribute, otherwise it returns None.

strip() is just a method of the Python str class.

It would be helpful if you could tell me what you get in the Template Editor per my request above.

I have not coded in Python (yet)… I will have a look. Py is not strictly typed, so this might be a hint.
The output in the Template Editor is exactly what is expected AUX1 or AUX2 or CD or Tuner or whatever the AVR is set to. All rendered correctly including the infamous AUX1.
The question now is whether the call (I guess http)) to the AVR is rendered rendered correctly.