getState returns incorrect value even with 'Do not subscribe all states on start' off (after restart?)

[raintonr]

I have a script that sends changes in our Loxone objects to GPIOs on a Raspberry Pi (lighting control and such).

This has been working well for a long time, but... I have always noticed that after a restart of the Javascript adapter that some objects do not respond to the first change in a value and you have to toggle it on/off to get a response. After putting a tonne of debug in the script I find that this is due to:

When my script starts it reads initial states (from Loxone objects) with getState and sets a destination state. I don't do with with on('stateId1', 'stateId2'); because sometimes the values need to be inverted.

Anyway, this first getState call returns a state.val as true even though the Loxone object value is false (clearly seen in the admin web interface). After setting the initial value I do use on to detect and handle changes and these seem to work from the second change (as the first change seen actually does nothing due to the initial state being set with the opposite value).

So my code (that doesn't work) was something like:

function setupOn(src, dst, invert = false) {
    const srcState = getState(src);
    // srcState.val is wrong here!
    if (invert) {
        srcState.val = !srcState.val;
    }
    // ...
}

setupOn('loxone.0.140ff1fe-0375-43e0-fffff62eeb38b63d.AI2.active', 'rpi2.0.gpio.26.state', true);

I use this in the setupOn function as there are several IOs to handle.

The above does not work as srcState is returned with the wrong value after a restart of the Javascript adapter.

However, if one uses a callback, it does work all the time:

function setupOn(src, dst, invert = false) {
    getState(src, (err, srcState) => {
        if (err) {
            log(err, 'error');
        } else if (!srcState) {
            log(src + ' state is false!', 'error');
        } else {
            // srcState.val is now good.
            if (invert) {
                srcState.val = !srcState.val;
            }
            // ...
        }
    });
}

This is very odd. I thought with 'Do not subscribe all states on start' left unchecked that getState should always return the current value of a state without the need for a callback. At least that's what the documentation...

https://github.com/ioBroker/ioBroker.javascript/blob/master/docs/en/javascript.md#option---do-not-subscribe-all-states-on-start

... says. But as I have found, this is not always the case!

[Apollon77]

Which version of the adapter you use? I fixed various issues in this handling - especially on starting with 5.4.0 very early this year. Please enable debug log and provide such a log of such a case.

if you use "do not subscribe all states" you NEED TO use callbacks because the state values are not cached on startup unless you subscribe to them!

So if you want to use your original code then the "do not subscribe" setting needs to be off!

[raintonr]

Version 6.0.0 in /opt/iobroker/node_modules/iobroker.javascript, node: v12.22.5, js-controller: 4.0.23

Unsurprisingly I have been unable to reproduce this in a separate instance or even separate script. Even copying my original script with the sets removed (ie. a setupOn function that does nothing but read the state and log it).

This leads me to suspect a timing issue but without digging into the code cannot confirm.

[raintonr]

So after failing to re-produce the issue I put the old script code back & restarted adapter. Bug is back as value was read incorrectly. Stopped the adatper then re-ran from the command line with debug enabled sending output to a log. No issues as value was read OK. Exited from the command line and re-started from web interface. Value was read OK even though this exact same script incorrectly read the value just a few minutes earlier.

Bugs like this are horrible to solve, but I just can't trust getState without a callback so think I'm going to change all my code to use them and tell the adapter not to subscribe to all. Allegedly this will yield better performance anyhow.

[winnyschuster]

what if you try like so, using async version of getState()

async function bla() {
    log((await getStateAsync('0_userdata.0.json')).val);
}

bla()

[Apollon77]

@raintonr As said I invested a looot time to dig into such issues and thought I discovered all loopholes ... The issue is that JavaScript functions like "getState" simulate an synchronous behaviour and we need to do several tricks for that.

It would be awesome if you could add maybe some additional logs and try to find out the reason ...

[raintonr]

The issue is that JavaScript functions like "getState" simulate an synchronous behaviour and we need to do several tricks for that.

Ah. Erm... this sounds ominous. I will look at the code in the adapter and see what is actually happening. I had assumed that with 'subscribe all states' on, every change in the DB was passed to the adapter, which keeps a cache of them all and as such getState can instantly return the correct value from that cache. Is that not the case?

It would be awesome if you could add maybe some additional logs and try to find out the reason ...

It would be for sure :smile: But as I said, when I ran with debug the problem went away :disappointed:

[Apollon77]

Is that not the case?

Exactly this is the case ... BUT because all stuff around is asynchronous there are several special cases (examples: while readon initial data thre can be new updates ... this is handled. You do a setState and before this is really executed you read the same value with getState ... also this is handed with a 99,9999% chance to work as expected because of edge cases you can not fix with such an approach ;-)

[Apollon77]

It would be for sure 😄 But as I said, when I ran with debug the problem went away 😞

thats why my proposal was to just add some additional debugs and not use the full debug log stuff

[stale[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within the next 7 days. Please check if the issue is still relevant in the most current version of the adapter and tell us. Also check that all relevant details, logs and reproduction steps are included and update them if needed. Thank you for your contributions. Dieses Problem wurde automatisch als veraltet markiert, da es in letzter Zeit keine Aktivitäten gab. Es wird geschlossen, wenn nicht innerhalb der nächsten 7 Tage weitere Aktivitäten stattfinden. Bitte überprüft, ob das Problem auch in der aktuellsten Version des Adapters noch relevant ist, und teilt uns dies mit. Überprüft auch, ob alle relevanten Details, Logs und Reproduktionsschritte enthalten sind bzw. aktualisiert diese. Vielen Dank für Eure Unterstützung.