[BUG] actions not processed in the right way

[Bascht74]

Bug report

Description

I added the a configuration for a light controller and slight movements (one step) up & down are processed wrong.

As you can see, I rotate the controller just one step
11:51:50.689812 --> brightness_move_up
11:51:50.694040 --> brightness_stop

ControllerX than runs a bit later:
11:51:50.695491 Running Predefined (hold) now
11:51:50.697701 Running Predefined (release) now

but then it executed @ 11:51:50.704844 a move_up till the end @11:51:50.972051 --> see log further down
So it did processed the hold, but not the fired release event...

I read the FAQ about it, but this is not true here:

This is probably happening to you sometimes and is because the stop/release action has not been fired. This can happen due to:
A rotation is too fast and confusing to know if it stopped or not.
The network is overloaded.
The server cannot handle the requests on time.
The controller and the light are far distanced from the coordinator.

Starting and stopping is fired and in the right order. Stop event is after start event...
Network is not overloaded. Every command is processed, server handled the request.
Controller is right next to the coordinator. Server is an NUC I5, so enough power...

It does seem that controllerX needed a bit of time to get the automatisation started and then the release is not queued in a working way or fired after the automatisation started (maybe before).

Additional information

• Devices involved:
• Model: MFKZQ01LM as Light (E1744)
• Integration: z2m
• AppDaemon version: 4.2.1, Python version is 3.9.7
• ControllerX version: ControllerX v4.19.0
• HACS version (if installed from there): 1.25.1
• Home Assistant Core version: Core 2022.6.0b0

AppDaemon app configuration

secrets: /config/secrets.yaml
appdaemon:
  latitude: [xxx] --> my lat
  longitude: [xxx] --> my long
  elevation: 2
  time_zone: Europe/Amsterdam
  # You can add `missing_app_warnings` if you don't want any
  # warning spam from ControllerX when starting AppDaemon
  missing_app_warnings: 0
  plugins:
    HASS:
      type: hass
    MQTT:
      type: mqtt
      namespace: mqtt # This is important
      client_host: core-mosquitto
      client_user: mqtt
      client_password: [xxx] --> my password
http:
  url: http://127.0.0.1:5050
admin:
api:
hadashboard:

----

schalter_eg_wohnzimmer_deckenfluter_controller:
  module: controllerx
  class: MFKZQ01LMLightController
  controller: Schalter_EG_Wohnzimmer_Deckenfluter
  integration:
    name: z2m
    listen_to: mqtt
  light: light.lampe_eg_wohnzimmer_deckenfluter # shelly light
  automatic_steps: 50
delay: 50
  actions:
    - brightness_move_down
    - brightness_move_up
    - brightness_stop
    - toggle
    - brightness_step_up # light@window
    - brightness_step_down # light@window
  mapping:
    toggle: toggle
    brightness_stop: release
    brightness_move_down: 
      action: hold
      attribute: brightness
      direction: down
      mode: stop
    brightness_move_up: 
      action: hold
      attribute: brightness
      direction: up
      mode: stop
    brightness_step_up:
      service: light.toggle
      data:
        entity_id: light.lampe_eg_wohnzimmer_fenster
    brightness_step_down: 
      service: light.toggle
      data:
        entity_id: light.lampe_eg_wohnzimmer_fenster

Logs

2022-05-26 11:51:39.793956 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running `Predefined (release)` now
2022-05-26 11:51:50.689812 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🎮 Button event triggered: `brightness_move_up`
2022-05-26 11:51:50.691879 WARNING schalter_eg_wohnzimmer_deckenfluter_controller: ⚠️ There is no `action` in the MQTT topic payload
2022-05-26 11:51:50.694040 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🎮 Button event triggered: `brightness_stop`
2022-05-26 11:51:50.695491 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running `Predefined (hold)` now
2022-05-26 11:51:50.697701 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running `Predefined (release)` now
2022-05-26 11:51:50.704844 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 142.40
  - transition: 0.05
2022-05-26 11:51:50.758918 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 167.80
  - transition: 0.05
2022-05-26 11:51:50.812248 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 193.20
  - transition: 0.05
2022-05-26 11:51:50.864947 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 218.60
  - transition: 0.05
2022-05-26 11:51:50.918441 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 244.00
  - transition: 0.05
2022-05-26 11:51:50.972051 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 
🤖 Service: light.turn_on
  - entity_id: light.lampe_eg_wohnzimmer_deckenfluter
  - brightness: 255
  - transition: 0.05

Additional Context

If two events are fired close by for the same device they should be executed in the right order so that they can be processed.
Thx for ControllerX, other devices work very well!

[xaviml]

Hi @Bascht74,

Sorry you are experiencing this issue. Although this is a bug, it is "expected" since behind the scenes it uses event queues to handle these events. Knowing that both actions were almost at the same time, the scheduler took the release first before the hold.

For fixing this, I could deliberately make that release actions cannot be executed after X milliseconds have passed, but that would compromise the performance for the most use cases where release is not sent 0.001s after a hold action. Therefore, the only fix I have in my hands is to add an attribute that by default would work as usual, but if added, it would fix problems like yours. For this, I could add a new release_delay which users could change to true if they are experiencing this. By default, it would be false to not affect the performance of other users. Would this work for you?

In the meantime, you could use action_delay to indicate release actions to delay small time (e.g.: 0.1s):

schalter_eg_wohnzimmer_deckenfluter_controller:
  module: controllerx
  class: MFKZQ01LMLightController
  controller: Schalter_EG_Wohnzimmer_Deckenfluter
  integration:
    name: z2m
    listen_to: mqtt
  light: light.lampe_eg_wohnzimmer_deckenfluter # shelly light
  automatic_steps: 50
  delay: 50
  action_delay:
    brightness_stop: 0.1
  actions:
    - brightness_move_down
    - brightness_move_up
    - brightness_stop
    - toggle
    - brightness_step_up # light@window
    - brightness_step_down # light@window
  mapping:
    toggle: toggle
    brightness_stop: release
    brightness_move_down: 
      action: hold
      attribute: brightness
      direction: down
      mode: stop
    brightness_move_up: 
      action: hold
      attribute: brightness
      direction: up
      mode: stop
    brightness_step_up:
      service: light.toggle
      data:
        entity_id: light.lampe_eg_wohnzimmer_fenster
    brightness_step_down: 
      service: light.toggle
      data:

With the new action_delay I added, every time the brightness_stop is fired, it will wait for 0.1s to actually run. You can adjust the time until you do not experience the problem.

Regards,
Xavi M.

[xaviml]

Hi @Bascht74 ,

I added the release_delay into the main branch, it will be released in next version. You can see development documentation refreshed now: https://controllerx.netlify.app/controllerx/faq/#7-when-holding-or-rotating-the-controller-especially-the-symfonisk-e1744-it-doesnt-stop-changing-the-brightness-or-volume

Regards,
Xavi M.

[Bascht74]

Great. Thank you! Looking forward to it.

[Bascht74]

Right now ControllerX is the only possibility to get all my switches working. Don’t understand why those are not getting more love from HA Core. Glad you fill in the gap here…!

[xaviml]

Hi @Bascht74,

I just released ControllerX v4.20.0 with the new release_delay attribute that you can use to fix this problem.

Let me know if you have any problems with it. I will close the ticket for now.

Regards,
Xavi M.

[Bascht74]

Hi @xaviml ,

I tried out the new attribute and it worked. No "jumps" anymore because the hold option never gets stopped by release.

But now it seems that 100ms is too much, because if you dial slowly it will stop the next event and/or execute too much hold changes.
I think it would be better so enter a value, default could by "0" (ms). release_delay: 25 --> Add 25 ms of delay. So you can find a sweet spot here.

Configuration:

schalter_eg_wohnzimmer_deckenfluter_controller: #OK
  module: controllerx
  class: MFKZQ01LMLightController
  controller: Schalter_EG_Wohnzimmer_Deckenfluter
  integration:
    name: z2m
    listen_to: mqtt
  light: light.lampe_eg_wohnzimmer_deckenfluter
  delay: 50
  release_delay: true # would like to set it to a value e.g. 25 [ms]
  automatic_steps: 50
  actions:
    - brightness_move_down
    - brightness_move_up
    - brightness_stop
    - toggle
    - brightness_step_up # light@window
    - brightness_step_down # light@window
  mapping:
    toggle: toggle
    brightness_stop: release
    brightness_move_down: 
      action: hold
      attribute: brightness
      direction: down
      mode: stop
    brightness_move_up: 
      action: hold
      attribute: brightness
      direction: up
      mode: stop
    brightness_step_up:
      service: light.toggle
      data:
        entity_id: light.lampe_eg_wohnzimmer_fenster
    brightness_step_down: 
      service: light.toggle
      data:
        entity_id: light.lampe_eg_wohnzimmer_fenster

Logs:
2022-05-31 00:58:22.673616 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🎮 Button event triggered: brightness_stop
2022-05-31 00:58:22.675312 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running Predefined (release) now
2022-05-31 00:58:22.705292 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🎮 Button event triggered: brightness_move_down
2022-05-31 00:58:22.706550 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running Predefined (hold) now
2022-05-31 00:58:22.766162 INFO schalter_eg_wohnzimmer_deckenfluter_controller:
🤖 Service: light.turn_on

• entity_id: light.lampe_eg_wohnzimmer_deckenfluter
• brightness: 165.28
• transition: 0.10
  2022-05-31 00:58:26.649042 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🎮 Button event triggered: brightness_stop
  2022-05-31 00:58:26.650405 INFO schalter_eg_wohnzimmer_deckenfluter_controller: 🏃 Running Predefined (release) now

[xaviml]

Hi @Bascht74 , I created following ticket to tackle this request.

#497

[Bascht74]

Thx!!!