UncleSamSwiss/ioBroker.loxone

activeMoods of lighting controller can get stuck/not sync properly

Closed this issue · 19 comments

I have a separate adapter that is using the activeMoods state for a lighting controller to turn the lights on/off & to different scenes.

This seems to work for a while, but at some point, something happens (I have not discovered what yet) that causes things to stop working.

When things are working as they should, one can open the admin objects list and modify activeMoods state to place one or more mood names there. Saving sends a command to Loxone and the lighting controller within Loxone reflects the change. My foreign adapter can update activeMoods in the same way and everything is good.

When the problem occurs, trying to modify the activeMoods results in the state change not being saved and the old state returning in red text. No updates are sent to Loxone at all and it appears no updates are received either.

I have the same issue.
The adapter works at this point fine for the other things the adapter control.
Only the activeMoods state doesn't work.

macpo commented

I recognized the same behaviour. It startet with the last update of the adapter to 2.0.2. I am not sure but I think the former version was 1.0.0 or 1.1.0...

I have added some checking code to master. Please try installing the adapter directly from GitHub and let me know if this fixes your issues. If not, additional logging should be available.

I have added some checking code to master. Please try installing the adapter directly from GitHub and let me know if this fixes your issues. If not, additional logging should be available.

Unfortunately I have only seen this happen a couple times but never since I reported this issue. It would be hard to determine if what you just did had an effect based on that.

As an aside: it's good practice to create a new branch for issues you're working on (I call mine issue/xx/SomeDescription but up to you) - that way people interested in that issue can just look at that branch differences to see what you've done. It's also good practice to begin commit messages with '#' + the issue number. Ie 849f500 should read, "#58 Improved handling of activeMoods for LightControllerV2." - if you do this then all commits for an issue are shown here on the issue page.

Unfortunately I have only seen this happen a couple times but never since I reported this issue. It would be hard to determine if what you just did had an effect based on that.

Ah... happened again this morning. Which lead me to question what has changed? Well... I made a slight config tweak so the Miniserver restarted. Maybe this is what causes things to get in a mess? Will investigate further.

Edit: In fact, yes, seems this is to do with Miniserver restarts. I just restarted again and this time a whole load of power monitoring objects I have setup got stuck. Not nice :(

macpo commented

First I tested the property activeMoods and it did not work. After the update from GitHub it worked as expected.

So in my installation the property activeMoods did not work at all with version 2.0.2.

macpo commented

Ah... happened again this morning. Which lead me to question what has changed? Well... I made a slight config tweak so the Miniserver restarted. Maybe this is what causes things to get in a mess? Will investigate further.

The push-button and the bulb on my side are "attached" with ioBroker and "controled" with Loxone. The push on the button sends a command to Loxone and Loxone sends the command to the bulb. Both using javascript.

Sometimes the command to the bulb was not received from Loxone, sometimes it seemed that the commands were collected and then sent all together which results in a fast changing bulb.

Up to now I do not know if the loxone adapter or Loxone do not send the command. Everytime I want to investigate it works.

I can confirm that after taking master (with 849f500) the problem persists.

The update don't help by solving the problem.
I have the same problem like before.

Sometimes the command to the bulb was not received from Loxone, sometimes it seemed that the commands were collected and then sent all together which results in a fast changing bulb.

This ("commands were collected and then sent all together") happens when the adapter first starts. It loads the structure file from loxone which can take some time to process on a slow machine (around 15s on an RPi 3B+ here). During this time, changes are cached and replayed once the structure file processing is complete. In my installation It takes around 0.2s to replay all the events after the first connection.

But as I note in #61, this cache & replay only takes place on the first connection after the adapter starts which I think is a bug and can lead to events being lost.

In another adapter I have simplified the entire connection handling: if the device disconnects, I restart the adapter. Like that, I'm always sure to have a proper connection.

Do you think this would be a good solution here? Reconnection will take some more time (as ioBroker doesn't immediately restart the adapter), but we would be on the "safe" side.

An adapter restart sounds like a kludge. I'm pretty sure if you set cacheEvents to true when a connection is closed that would handle 99.9% of cases. Adding a FIFO as discussed in #61 should catch the rest.

Adding a FIFO as discussed in #61 should catch the rest.

... which I have now done. Am testing this code, but looks all good for now. Feel free to try this branch and report problems if you are game ;)

https://github.com/raintonr/ioBroker.loxone/tree/issue/61/EventQueue

macpo commented

The first tests were good. It seems very smooth...

@raintonr In general the code in your issue/61/EventQueue branch looks good. I would prefer to use await everywhere instead of mixing await with explicitly returning promises (and of course methods should simply return Promise<void> instead of specific promises like ioBroker.SetStatePromise):
One example:

            (name: string, value: CurrentStateValue) => {
                const rgb = this.loxoneColorToRgb(value);
                if (rgb !== undefined) {
                    this.setStateAck(name, rgb[0]);
                    return this.setStateAck(name, rgb[0]);
                }
                return this.resolvedPromise();
            }

should rather be

            async (name: string, value: CurrentStateValue) => {
                const rgb = this.loxoneColorToRgb(value);
                if (rgb !== undefined) {
                    this.setStateAck(name, rgb[0]);
                    await this.setStateAck(name, rgb[0]);
                }
            }

In addition, I see the following code as another issue: the loop can't be interrupted and will continue to push things out. And since handleEventQueue() is always called without caring for the returned promise, it is done completely asynchronously. So, if shortly after a reconnect, the connection is lost again and reconnected, it might still be handling old events while already working on the new structure file (thus changing objects).

            let evt: LoxoneEvent | null;
            while ((evt = this.eventsQueue.dequeue())) {
                this.log.debug(`Dequeued event UUID: ${evt.uuid}`);
                await this.handleEvent(evt);
            }

At least we should clear the queue if we get reconnected.

I would prefer to use await everywhere instead of mixing await with explicitly returning promises... and of course methods should simply return Promise<void>

Ultimately events coming in end up in a call to setStateAsync which returns a SetStatePromise type. Don't think I have got an await anywhere for one of those (so no mixing) and am just letting the promise percolate up to the caller.

As for using SetStatePromise over a Promise<void>. Again, I'm just letting the result of setStateAsync percolate up. Why would one exchange a specific type for a more generic one - isn't that against the ethos of TS?

the [event queue] loop can't be interrupted

This is a valid point. To break out of that loop all one has to do is call eventsQueue.clear(). IMHO this is better done on disconnect than on connect so will add that call.

I would prefer to use await everywhere instead of mixing...

Upon reflection... yes... that's also a valid point and cleaner so have updated accordingly.

P.S. We really should discuss this over on #61 ;)

@raintonr I suggest you make a PR, then we can discuss it there and we can use the comment feature instead of me copying code fragments.

Fixed in version 2.1.0