Item states are being reset

[danielmorlock]

Since some weeks, I'm facing a strange issue where the item states are being reset instantly. So this code:

        val NumberItem item_start_hours = ScriptServiceUtil.getItemRegistry.getItem("worx_landroid_scheduler_" + today_str_lower + "_start_hours") as NumberItem
        val NumberItem item_start_minutes = ScriptServiceUtil.getItemRegistry.getItem("worx_landroid_scheduler_" + today_str_lower + "_start_minutes") as NumberItem        
        val SwitchItem item_edge_cut = ScriptServiceUtil.getItemRegistry.getItem("worx_landroid_scheduler_" + today_str_lower + "_edge_cut") as SwitchItem
        val NumberItem item_duration = ScriptServiceUtil.getItemRegistry.getItem("worx_landroid_scheduler_" + today_str_lower + "_duration") as NumberItem
        val SwitchItem item_enable = ScriptServiceUtil.getItemRegistry.getItem("worx_landroid_scheduler_" + today_str_lower + "_enable") as SwitchItem

        item_edge_cut.sendCommand(ON)
        item_start_hours.sendCommand(start_hours)
        item_start_minutes.sendCommand(start_mins)
        item_duration.sendCommand(landroid_work_duration_min)
        item_enable.sendCommand(ON)

Results in the following logs:

2021-06-10 11:53:44.943 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_edge_cut' changed from OFF to ON
2021-06-10 11:53:44.945 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_start_hours' changed from 0 to 12
2021-06-10 11:53:44.948 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_duration' changed from 0 to 240
2021-06-10 11:53:44.950 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_enable' predicted to become ON
2021-06-10 11:53:44.962 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_enable' changed from OFF to ON
2021-06-10 11:53:47.111 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_start_hours' changed from 12 to 0
2021-06-10 11:53:47.117 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_edge_cut' changed from ON to OFF

If you check worx_landroid_scheduler_thursday_start_hours, it is correctly changed from "0" to "12" at 2021-06-10 11:53:44.945 but changed back from "12" to "0" at 2021-06-10 11:53:47.111.

I'm using OH 3.0.0 and the latest release from the worxlandroid binding. Same code worked perfectly last year.

Any ideas how to further investigate this?

[nibi79]

Can you try to reboot the system?

[nibi79]

or try to set item_enable.sendCommand(ON) first and after that the schedule times
when it works again you can change it back again

[danielmorlock]

I rebootet the system, and updated to OH 3.0.1 in the meantime. I changed the code to:

        item_enable.sendCommand(ON)
        item_edge_cut.sendCommand(ON)
        item_start_hours.sendCommand(start_hours)
        item_start_minutes.sendCommand(start_mins)
        item_duration.sendCommand(landroid_work_duration_min) 

Unfortunately, still the same behavior:

2021-06-10 16:40:57.932 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'worx_landroid_scheduler_thursday_enable' received command ON
2021-06-10 16:40:57.938 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'worx_landroid_scheduler_thursday_edge_cut' received command ON
2021-06-10 16:40:57.939 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_enable' predicted to become ON
2021-06-10 16:40:57.952 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'worx_landroid_scheduler_thursday_start_hours' received command 17
2021-06-10 16:40:57.960 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'worx_landroid_scheduler_thursday_start_minutes' received command 0
2021-06-10 16:40:57.969 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'worx_landroid_scheduler_thursday_duration' received command 240
2021-06-10 16:40:57.970 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_edge_cut' predicted to become ON
2021-06-10 16:40:57.975 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_start_hours' predicted to become 17
2021-06-10 16:40:57.982 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_start_minutes' predicted to become 0
2021-06-10 16:40:57.988 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'worx_landroid_scheduler_thursday_duration' predicted to become 240
2021-06-10 16:40:57.993 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_start_hours' changed from 14 to 17
2021-06-10 16:40:57.994 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_duration' changed from 300 to 240
2021-06-10 16:41:00.113 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_start_hours' changed from 17 to 14
2021-06-10 16:41:00.114 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_duration' changed from 240 to 0
2021-06-10 16:41:00.114 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'worx_landroid_scheduler_thursday_enable' changed from ON to OFF

[danielmorlock]

Workaround, but I'm not proud of this:

        var timeout = 10;
        while(timeout >= 0) {
            logInfo("landroid", "... trying to activate \"item_enable\" ...");
            item_enable.sendCommand(ON);
            Thread::sleep(1000);
            if(item_enable.state == ON) {
                logInfo("landroid", "... sucess: " + item_enable.state.toString);
                timeout = -1;
            } else {
                timeout --;
                if(timeout > 0) {
                    logInfo("landroid", "... re-trying.");
                } else {
                    logInfo("landroid", "... giving up :-(");
                }
            }
        }

[BobMiles]

Hi,

the problem is as follows:

• A single command is OK and will work. The MQTT payload is sent and AWS answers with a full MQTT state payload. The binding reads the answer from AWS and updates all channels accordingly

• Multiple consecutive commands will end up in a race condition: The binding sends out multiple messages in rapid succession, but the worx API will only accept the first message and answer back with only that change, sending again a full state message. In that message, all the other items are still in their original state, causing the binding to update the channels to their original value (instead of what the commands would have been).

This could be prevented by using:

1. A handshake queue where the binding awaits an answer for each command and only then issues the next command
2. A buffer where the binding doesn't send changes immediately and after a certain delay where no more commands happen it will send out a new payload with all the buffered commands

Ideally, a combination of both as the API is rate limited very strictly.

My quick and dirty workaround: I use timers in ECMAScript 11 to delay each command by 30 seconds from the last:
`
items.getItem("LandroidM500Plus_CfgSc"+dayString+"_ScheduleStartHour").sendCommand(schedule1StartHour)
setTimeout(function() {
items.getItem("LandroidM500Plus_CfgSc" + dayString + "_ScheduleStartMinutes").sendCommand(schedule1StartMinute);
}, 30000); // Adjust the delay time (in milliseconds) as needed
setTimeout(function() {
items.getItem("LandroidM500Plus_CfgSc" + dayString + "2_ScheduleStartHour").sendCommand(schedule2StartHour);
}, 60000); // Adjust the delay time (in milliseconds) as needed

setTimeout(function() {
items.getItem("LandroidM500Plus_CfgSc" + dayString + "2_ScheduleStartMinutes").sendCommand(schedule2StartMinute);
}, 90000); // Adjust the delay time (in milliseconds) as needed

setTimeout(function() {
items.getItem("LandroidM500Plus_CfgSc" + dayString + "_ScheduleDuration").sendCommand(duration);
}, 120000); // Adjust the delay time (in milliseconds) as needed

`