Xiaomi Mi IO Binding - String-Item and received command rule problem

Hi all,

I have a problem with the xiaomi binding (https://www.openhab.org/addons/bindings/miio/). I own a xiaomi vacuumer which I have integrated within openhab. I control the vacuumer via Alexa and also via the xiaomi app.

My problem is that the “recieved command” rule (please see below) is not triggered when I change the status of the VacuumerActionControl within the xiaomi app :frowning: - and this causes some troubles.

Any idea how I can configure the setup in a way that in all cases within a rule the status change of the VacuumerActionControl item gets recognized properly?

Item

String VacuumerActionControl  "Vacuum Control"     (gVac)     {channel="miio:vacuum:vacumground:actions#control" }

Rule:

rule "vacuumer_actionControl_switch"
when
    Item VacuumerActionControl received command
then
    // not triggered when I control the vacuumer within the xiaomi app :(
end


rule "vacuumer_actionControl_switch_changed"
when
    Item VacuumerActionControl changed
then
   // triggered when vacuumer gets controlled within the xiaomi app - but multiple times
end

Thanks in advance
Dennis

The general flow through openHAB is that UI users (or rules) actions create commands, that bindings pass out to real devices. Devices pass info to bindings, which cause state updates. (with a few exceptions)

As your Item changes state, that is what you need to use in OH to “listen” for something else making changes (the xiaomi app).

If you tell us more about the multiple changes you see (maybe an events.log snippet) we can probably help you work with it. Maybe there is one particular change you are interested in, or just want to act only once in five minutes, or something.

Hi Rossko57,

many thanks for your reply! I checked the “changed rule” in detail right now and I realized that the behavior is as follows:

Rule:

rule "vacuumer_actionControl_switch_changed"
when
    Item VacuumerActionControl changed
then
    logInfo("vacuumer_actionControl_switch", "changed: " + VacuumerActionControl)	
end

Usercase1: Change the vacuumer state within the xiaomi app
In this scenario the changed rule is triggered correctly. When the vacuumer gets switched on I recieve a single entry like:

2019-10-19 15:26:42.417 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])

Same for sending the vacuumer back to dock:
2019-10-19 15:25:58.979 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])

Thus usecase1 works as expected.

Usecase2: Change the vacuumer state within openhab (basicUI)

If I switch from dock to vacuumer the rule is triggered 3 times in a row:

2019-10-19 15:51:22.985 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-19 15:51:23.013 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-19 15:51:47.343 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])

The first two times are triggered directly afterwards and then after 20 seconds the porper state (=vacuum) is set

If I switch from vacuum to dock I can monitor the very same behavior:

2019-10-19 15:52:06.232 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-19 15:52:06.360 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-19 15:52:17.466 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])

As you can see in Usecase2 the rule is triggered always 3 times instead of just once. Any idea what’s going wrong here?

Cheers
Dennis

I think if you look in your events.log you will get a clearer view of what is happening.

Hmmm… unfortunately not :frowning: I changed it via basicUI from dock to vacuum

These log entries:

2019-10-21 18:21:27.554 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-21 18:21:27.658 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-21 18:22:02.099 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])

Do fit to the following event logs:

2019-10-21 18:21:27.549 [ome.event.ItemCommandEvent] - Item 'VacuumerActionControl' received command vacuum
2019-10-21 18:21:27.553 [nt.ItemStatePredictedEvent] - VacuumerActionControl predicted to become vacuum
2019-10-21 18:21:27.555 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from dock to vacuum
2019-10-21 18:21:27.658 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from vacuum to dock
2019-10-21 18:21:32.139 [vent.ItemStateChangedEvent] - miNetLife changed from 53637 to 53697
2019-10-21 18:22:02.098 [vent.ItemStateChangedEvent] - statusBat changed from 99 to 98
2019-10-21 18:22:02.098 [vent.ItemStateChangedEvent] - statusArea changed from 1.44 to 0.955
2019-10-21 18:22:02.098 [vent.ItemStateChangedEvent] - statusClean changed from 0 to 1
2019-10-21 18:22:02.099 [vent.ItemStateChangedEvent] - statusStatus changed from Charging to Cleaning
2019-10-21 18:22:02.099 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from dock to vacuum

If I trigger the same status change via the xiaomi app I receive the following event logs:

2019-10-21 19:07:19.159 [vent.ItemStateChangedEvent] - statusClean changed from 0 to 1
2019-10-21 19:07:19.159 [vent.ItemStateChangedEvent] - statusStatus changed from Charging to Cleaning
2019-10-21 19:07:19.159 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from dock to vacuum

Thus the only difference is the ItemStatePredictedEvent stuff which I can see… any ideas if this is related to the issue?

I did some further researches and I think I figured out the root cause for this problem.

I enabled the debug logs for the xiaomi binding. Here I can see that the vacuumer directly after the command was send still replies that the status is “in dock” (status codes can be found here: https://github.com/marcelrv/XiaomiRobotVacuumProtocol/blob/master/StatusMessage.md).

Thus the behavior is:

1.: Button in basicUI is pressed => vacuumer is set to “vacuum”
2.: vacuumer recieved the GET_STATUS response (state=8 (charging)) => vacuumer is set to “dock”
3.: periodic update kicks in => state=5 (cleaning)) ==> vacuumer is set to “vacuum”

I assume this is an issue within the xiaomi binding :frowning:

//----- dock2vacuum triggered from basicUI - event.logs

2019-10-21 19:42:50.494 [DEBUG] [o.internal.handler.MiIoVacuumHandler] - Periodic update for 'miio:vacuum:vacumground' (miio:vacuum)
2019-10-21 19:42:50.494 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8738,"method":"get_dnd_timer","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 1)
2019-10-21 19:42:50.494 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.497 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.497 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8739,"method":"get_clean_summary","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 2)
2019-10-21 19:42:50.497 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.499 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.499 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8740,"method":"get_status","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 3)
2019-10-21 19:42:50.500 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.502 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.502 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8741,"method":"miIO.info","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 4)
2019-10-21 19:42:50.502 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.504 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.505 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8742,"method":"get_consumable","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 5)
2019-10-21 19:42:50.505 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.507 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.548 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: DND_GET, result: [{"start_hour":22,"start_minute":0,"end_hour":8,"end_minute":0,"enabled":1}], fullresponse: {"result":[{"start_hour":22,"start_minute":0,"end_hour":8,"end_minute":0,"enabled":1}],"id":8738}
2019-10-21 19:42:50.557 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: CLEAN_SUMMARY_GET, result: [136320,1887000000,94,[1571679652,1571678891,1571678745,1571678652,1571677649,1571674906,1571674636,1571674456,1571652017,1571493087,1571492514,1571491658,1571491563,1571491487,1571491334,1571392800,1571306400,1571220001,1571133600,1571047202]], fullresponse: {"result":[136320,1887000000,94,[1571679652,1571678891,1571678745,1571678652,1571677649,1571674906,1571674636,1571674456,1571652017,1571493087,1571492514,1571491658,1571491563,1571491487,1571491334,1571392800,1571306400,1571220001,1571133600,1571047202]],"id":8739}
2019-10-21 19:42:50.557 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8743,"method":"get_clean_record","params":[1571679652]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 4)
2019-10-21 19:42:50.557 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:50.560 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:50.565 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: GET_STATUS, result: [{"msg_ver":2,"msg_seq":2568,"state":8,"battery":72,"clean_time":72,"clean_area":1977500,"error_code":0,"map_present":1,"in_cleaning":0,"in_returning":0,"in_fresh_state":1,"lab_status":1,"fan_power":60,"dnd_enabled":0}], fullresponse: {"result":[{"msg_ver":2,"msg_seq":2568,"state":8,"battery":72,"clean_time":72,"clean_area":1977500,"error_code":0,"map_present":1,"in_cleaning":0,"in_returning":0,"in_fresh_state":1,"lab_status":1,"fan_power":60,"dnd_enabled":0}],"id":8740}
2019-10-21 19:42:50.569 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: MIIO_INFO, result: {"hw_ver":"Linux","fw_ver":"3.3.9_001886","ap":{"ssid":"mushroom kingdom","bssid":"DC:9F:DB:B5:49:A0","rssi":-66},"netif":{"localIp":"10.10.10.38","mask":"255.255.255.0","gw":"10.10.10.1"},"model":"roborock.vacuum.s5","mac":"04:CF:8C:F9:17:46","token":"4162504833574b625a5733663865505a","life":58575}, fullresponse: {"partner_id":"","id":8741,"code":0,"message":"ok","result":{"hw_ver":"Linux","fw_ver":"3.3.9_001886","ap":{"ssid":"mushroom kingdom","bssid":"DC:9F:DB:B5:49:A0","rssi":-66},"netif":{"localIp":"10.10.10.38","mask":"255.255.255.0","gw":"10.10.10.1"},"model":"roborock.vacuum.s5","mac":"04:CF:8C:F9:17:46","token":"4162504833574b625a5733663865505a","life":58575}}
2019-10-21 19:42:50.575 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: CONSUMABLES_GET, result: [{"main_brush_work_time":136320,"side_brush_work_time":136320,"filter_work_time":136320,"sensor_dirty_time":136320}], fullresponse: {"result":[{"main_brush_work_time":136320,"side_brush_work_time":136320,"filter_work_time":136320,"sensor_dirty_time":136320}],"id":8742}
2019-10-21 19:42:50.581 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: CLEAN_RECORD_GET, result: [[1571679652,1571679764,72,1977500,0,0]], fullresponse: {"result":[[1571679652,1571679764,72,1977500,0,0]],"id":8743}
2019-10-21 19:42:53.029 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-21 19:42:53.031 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8744,"method":"app_start","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 1)
2019-10-21 19:42:53.031 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:53.034 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:53.034 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8745,"method":"get_status","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 2)
2019-10-21 19:42:53.035 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:42:53.039 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:42:53.133 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: START_VACUUM, result: ["ok"], fullresponse: {"result":["ok"],"id":8744}
2019-10-21 19:42:53.141 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: GET_STATUS, result: [{"msg_ver":2,"msg_seq":2569,"state":8,"battery":72,"clean_time":72,"clean_area":1977500,"error_code":0,"map_present":1,"in_cleaning":0,"in_returning":0,"in_fresh_state":1,"lab_status":1,"fan_power":60,"dnd_enabled":0}], fullresponse: {"result":[{"msg_ver":2,"msg_seq":2569,"state":8,"battery":72,"clean_time":72,"clean_area":1977500,"error_code":0,"map_present":1,"in_cleaning":0,"in_returning":0,"in_fresh_state":1,"lab_status":1,"fan_power":60,"dnd_enabled":0}],"id":8745}
2019-10-21 19:42:53.143 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=dock, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-21 19:42:53.143 [INFO ] [script.vacuumer_actionControl_switch] - DOCK!!!!


2019-10-21 19:43:20.514 [DEBUG] [o.internal.handler.MiIoVacuumHandler] - Periodic update for 'miio:vacuum:vacumground' (miio:vacuum)
2019-10-21 19:43:20.514 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8746,"method":"get_dnd_timer","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 1)
2019-10-21 19:43:20.515 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:43:20.517 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:43:20.518 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8747,"method":"get_clean_summary","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 2)
2019-10-21 19:43:20.518 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:43:20.521 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:43:20.521 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8748,"method":"get_status","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 3)
2019-10-21 19:43:20.521 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:43:20.524 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:43:20.524 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Command added to Queue {"id":8749,"method":"get_consumable","params":[]} -> 10.10.10.38 (Device: 0F7965C5 token: 4162504833574B625A5733663865505A Queue: 4)
2019-10-21 19:43:20.524 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Sending Ping 0F7965C5 (10.10.10.38)
2019-10-21 19:43:20.526 [DEBUG] [nal.transport.MiIoAsyncCommunication] - Ping 0F7965C5 (10.10.10.38) success
2019-10-21 19:43:20.590 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: DND_GET, result: [{"start_hour":22,"start_minute":0,"end_hour":8,"end_minute":0,"enabled":1}], fullresponse: {"result":[{"start_hour":22,"start_minute":0,"end_hour":8,"end_minute":0,"enabled":1}],"id":8746}
2019-10-21 19:43:20.597 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: CLEAN_SUMMARY_GET, result: [136320,1887000000,94,[1571679652,1571678891,1571678745,1571678652,1571677649,1571674906,1571674636,1571674456,1571652017,1571493087,1571492514,1571491658,1571491563,1571491487,1571491334,1571392800,1571306400,1571220001,1571133600,1571047202]], fullresponse: {"result":[136320,1887000000,94,[1571679652,1571678891,1571678745,1571678652,1571677649,1571674906,1571674636,1571674456,1571652017,1571493087,1571492514,1571491658,1571491563,1571491487,1571491334,1571392800,1571306400,1571220001,1571133600,1571047202]],"id":8747}
2019-10-21 19:43:20.602 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: GET_STATUS, result: [{"msg_ver":2,"msg_seq":2571,"state":5,"battery":72,"clean_time":26,"clean_area":377500,"error_code":0,"map_present":1,"in_cleaning":1,"in_returning":0,"in_fresh_state":0,"lab_status":1,"fan_power":60,"dnd_enabled":0}], fullresponse: {"result":[{"msg_ver":2,"msg_seq":2571,"state":5,"battery":72,"clean_time":26,"clean_area":377500,"error_code":0,"map_present":1,"in_cleaning":1,"in_returning":0,"in_fresh_state":0,"lab_status":1,"fan_power":60,"dnd_enabled":0}],"id":8748}
2019-10-21 19:43:20.609 [INFO ] [script.vacuumer_actionControl_switch] - changed: VacuumerActionControl (Type=StringItem, State=vacuum, Label=Vacuum Control, Category=null, Groups=[gVac])
2019-10-21 19:43:20.612 [DEBUG] [internal.handler.MiIoAbstractHandler] - Received response for vacumground type: CONSUMABLES_GET, result: [{"main_brush_work_time":136320,"side_brush_work_time":136320,"filter_work_time":136320,"sensor_dirty_time":136320}], fullresponse: {"result":[{"main_brush_work_time":136320,"side_brush_work_time":136320,"filter_work_time":136320,"sensor_dirty_time":136320}],"id":8749}




//----- dock2vacuum triggered from basicUI - openhab.logs

2019-10-21 19:42:50.557 [vent.ItemStateChangedEvent] - historyTime changed from 2270 to 2272
2019-10-21 19:42:50.557 [vent.ItemStateChangedEvent] - historyArea changed from 1885.0225 to 1887.0
2019-10-21 19:42:50.558 [vent.ItemStateChangedEvent] - historyCount changed from 93 to 94
2019-10-21 19:42:50.566 [vent.ItemStateChangedEvent] - statusClean changed from 1 to 0
2019-10-21 19:42:50.566 [vent.ItemStateChangedEvent] - statusStatus changed from Returning Dock to Charging
2019-10-21 19:42:50.570 [vent.ItemStateChangedEvent] - miNetLife changed from 58515 to 58575
2019-10-21 19:42:53.025 [ome.event.ItemCommandEvent] - Item 'VacuumerActionControl' received command vacuum
2019-10-21 19:42:53.028 [nt.ItemStatePredictedEvent] - VacuumerActionControl predicted to become vacuum
2019-10-21 19:42:53.031 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from dock to vacuum
2019-10-21 19:42:53.143 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from vacuum to dock


2019-10-21 19:43:20.608 [vent.ItemStateChangedEvent] - statusArea changed from 1.9775 to 0.3775
2019-10-21 19:43:20.609 [vent.ItemStateChangedEvent] - statusTime changed from 1 to 0
2019-10-21 19:43:20.609 [vent.ItemStateChangedEvent] - statusClean changed from 0 to 1
2019-10-21 19:43:20.609 [vent.ItemStateChangedEvent] - statusStatus changed from Charging to Cleaning
2019-10-21 19:43:20.609 [vent.ItemStateChangedEvent] - VacuumerActionControl changed from dock to vacuum

Yes. When you send an openHAB command to your Item (from UI or rule), the autoupdate feature sees it - as well as your actual binding which will pass the command to the cleaner.
Autoupdate makes an educated guess about the likely outcome of the command, and issues its prediction.
That in turn causes an internal update of your Item.
The idea is to make a responsive user interface, even if the target device responds slowly (like yours) or even not at all.

In your case, shortly (100mS) after autoupdate has done its thing, your binding responds with the status of the cleaner. It’s the current status, before it has started to actually do the new command. That’s no use really, but openHAB does as it is told and updates your Item to this “old” status.

Much later, a new (presumably routine) status message arrives from the cleaner that now shows the new mode, and Item gets updated again.

So, what can you do? Multiple choice.

Autoupdate is configurable on a per-Item basis. So you turn it off for your problem Item with autoupdate="false" in its configuration.
That will leave your Item reflecting actual changes, your rules will work fine, but your UI display will be delayed (if you care).

Or, you can make your rules multiple-trigger proofed. When triggered, lock out any repeat action for a short period (say 8 or 10 seconds here)

What would be preferable is for the cleaner to respond to a command with the “new” status instead of “before” status. I do not know what options are available for you to configure.

Second best would be for the binding to issue a poll-after-command after a short delay.
The binding author @marcel_verpaalen did already look at this years ago, and made a change then. But a lot of binding changes since then.

1 Like

Design Pattern: Rule Latching is a better DP for that. Gatekeeper queues up the commands and processes them with suitable delays between them. Rule Latching is closer to what you described.