[groupepsa] GroupePSAHandlerTest unstable

[wborn]

This test failed in: https://github.com/wborn/openhab-addons/actions/runs/3257390882/jobs/5348631026

[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 8.74 s <<< FAILURE! - in org.openhab.binding.groupepsa.internal.things.GroupePSAHandlerTest
[ERROR] org.openhab.binding.groupepsa.internal.things.GroupePSAHandlerTest.intializeAndCheckChannels  Time elapsed: 8.561 s  <<< FAILURE!
org.mockito.exceptions.verification.WantedButNotInvoked: 

Wanted but not invoked:
thingCallback.statusUpdated(
    thing,
    <custom argument matcher>
);
-> at org.openhab.binding.groupepsa.internal.things.GroupePSAHandlerTest.intializeAndCheckChannels(GroupePSAHandlerTest.java:152)

However, there were exactly 12 interactions with this mock:
thingCallback.stateUpdated(
    a:b:c:doors#locked,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:battery#current,
    0 A
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:battery#voltage,
    87 V
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:environment#temperature,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:environment#daytime,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#ignition,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#moving,
    CLOSED
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#acceleration,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#speed,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#mileage,
    1539 km
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:position#position,
    11.2222222,22.1111111
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:position#heading,
    331 �
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

    at org.openhab.binding.groupepsa.internal.things.GroupePSAHandlerTest.intializeAndCheckChannels(GroupePSAHandlerTest.java:152)

[INFO] 
[INFO] Results:
[INFO] 
[ERROR] Failures: 
[ERROR]   GroupePSAHandlerTest.intializeAndCheckChannels:152 
Wanted but not invoked:
thingCallback.statusUpdated(
    thing,
    <custom argument matcher>
);
-> at org.openhab.binding.groupepsa.internal.things.GroupePSAHandlerTest.intializeAndCheckChannels(GroupePSAHandlerTest.java:152)

However, there were exactly 12 interactions with this mock:
thingCallback.stateUpdated(
    a:b:c:doors#locked,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:battery#current,
    0 A
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:battery#voltage,
    87 V
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:environment#temperature,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:environment#daytime,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#ignition,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#moving,
    CLOSED
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#acceleration,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#speed,
    UNDEF
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:motion#mileage,
    1539 km
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:position#position,
    11.2222222,22.1111111
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

thingCallback.stateUpdated(
    a:b:c:position#heading,
    331 �
);
-> at org.openhab.core.thing.binding.BaseThingHandler.updateState(BaseThingHandler.java:268)

[INFO] 
[ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0

[wborn]

Can you have a look at this @arjanmels?

[arjanmels]

I tried on the current HEAD 2c2097d6461efa805cbeb661902fa4611f5c8f10, but cannot reproduce the issue.

If it is still a problem, can you provide details how to reproduce?

[wborn]

It's still randomly failing @arjanmels, see:

https://ci.openhab.org/job/openHAB-Addons/1162/

I've also had parallel builds on my own computer fail due to this. So you can probably reproduce it by running the test with some CPU load on your system.

If it is not fixed I suggest to disable these unreliable tests so they do not waste peoples time.

[arjanmels]

I'll have a look (probably next week).

[arjanmels]

I think I found the problem. The timeouts in the verifies might be too short in certain circumstances. If I manually decrease it from 2 000ms to 1 000ms I start getting failures.

I have increased them from 2 000ms to 1 0000ms in #15574.