[Test failures] DMX SacnBridgeHandlerTest

[sjsf]

initializationOfBridgeHandler(org.eclipse.smarthome.binding.dmx.SacnBridgeHandlerTest)  Time elapsed: 10.076 sec  <<< FAILURE!
java.lang.AssertionError: 
Expected: is <ONLINE>
     but: was <OFFLINE>
    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
    at org.junit.Assert.assertThat(Assert.java:956)
    at org.junit.Assert.assertThat(Assert.java:923)
    at org.eclipse.smarthome.binding.dmx.SacnBridgeHandlerTest.lambda$1(SacnBridgeHandlerTest.java:87)

Occasionally seen, latest here: https://travis-ci.org/eclipse/smarthome/builds/276803373?utm_source=email&utm_medium=notification

[sjsf]

@J-N-K could you please have a look?

[J-N-K]

That's interesting. I'll have a closer look later. It seem that for some reason opening a UDP socket fails:

11:44:49.542 [main] DEBUG o.e.s.c.thing.internal.ThingManager - Calling initialize handler for thing 'dmx:sacn-bridge:sacnbridge' at 'org.eclipse.smarthome.binding.dmx.handler.SacnBridgeHandler@1339e7aa'. 11:44:49.542 [safeCall-1] DEBUG o.e.s.b.d.handler.SacnBridgeHandler - initializing sACN/E1.31 bridge dmx:sacn-bridge:sacnbridge 11:44:49.550 [safeCall-1] DEBUG o.e.s.b.d.handler.SacnBridgeHandler - using multicast mode to [/239.255.0.1:5568] for dmx:sacn-bridge:sacnbridge 11:44:49.550 [safeCall-1] DEBUG o.e.s.b.d.handler.SacnBridgeHandler - originating address is (null):0 for dmx:sacn-bridge:sacnbridge 11:44:49.550 [safeCall-1] DEBUG o.e.s.b.d.handler.SacnBridgeHandler - refresh mode set to always: false 11:44:49.550 [safeCall-1] DEBUG o.e.s.b.d.internal.DmxBridgeHandler - set refreshTime to 33 ms in thing dmx:sacn-bridge:sacnbridge 11:44:49.552 [ESH-thingHandler-2] DEBUG o.e.s.b.d.i.d.DmxOverEthernetHandler - opened socket 0.0.0.0/0.0.0.0:35119 in bridge dmx:sacn-bridge:sacnbridge 11:44:49.556 [safeCall-1] DEBUG o.e.s.b.d.handler.SacnBridgeHandler - updated configuration for sACN/E1.31 bridge dmx:sacn-bridge:sacnbridge 11:44:49.556 [main] DEBUG o.e.s.c.c.r.AbstractManagedProvider - Added new element dmx:sacn-bridge:sacnbridge to ManagedThingProvider. 11:44:49.585 [ESH-thingHandler-2] DEBUG o.e.s.b.d.i.d.DmxOverEthernetHandler - could not open socket 0.0.0.0/0.0.0.0:35119 in bridge dmx:sacn-bridge:sacnbridge 11:44:49.617 [ESH-thingHandler-2] DEBUG o.e.s.b.d.i.d.DmxOverEthernetHandler - could not open socket 0.0.0.0/0.0.0.0:35119 in bridge dmx:sacn-bridge:sacnbridge 11:44:49.650 [ESH-thingHandler-4] DEBUG o.e.s.b.d.i.d.DmxOverEthernetHandler - could not open socket 0.0.0.0/0.0.0.0:35119 in bridge dmx:sacn-bridge:sacnbridge

This in turn leads to OFFLINE status for the bridge and a test failure.

[sjsf]

So the good news is that the test somewhat is working correctly 😄 Thanks for looking into this.

[J-N-K]

I tried to reproduce it with several builds (maven on three machines, IDE on two machines). It's always working for me. Is someone able to reproduce that locally?

[maggu2810]

@J-N-K I will give it a try.

[maggu2810]

https://gist.github.com/maggu2810/6db0b13b095ad16190a4b09f206499f5

[J-N-K]

This is the same test, but a completely different reason. @maggu2810's test fails because no handler is available, although the log shows it has been correctly initialized and opened the socket sucessfully (which failed in @sjka's log from Travis above).

[J-N-K]

Is this still occuring? I have not seen failing tests recently.

[sjsf]

Let's imagine it magically fixed itself and wait until it happens again.

[sjsf]

Surprise, surprise: https://travis-ci.org/eclipse/smarthome/builds/313586515?utm_source=github_status&utm_medium=notification

Tests run: 3, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 10.214 sec <<< FAILURE! - in org.eclipse.smarthome.binding.dmx.SacnBridgeHandlerTest
initializationOfBridgeHandler(org.eclipse.smarthome.binding.dmx.SacnBridgeHandlerTest)  Time elapsed: 10.094 sec  <<< FAILURE!
java.lang.AssertionError: 
Expected: is <ONLINE>
     but: was <OFFLINE>
    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
    at org.junit.Assert.assertThat(Assert.java:956)
    at org.junit.Assert.assertThat(Assert.java:923)
    at org.eclipse.smarthome.binding.dmx.SacnBridgeHandlerTest.lambda$1(SacnBridgeHandlerTest.java:92)```

[J-N-K]

Unfortunately the log is unavailable. If I user your link, the referenced build failed in Paper UI, not in the DMX tests. From the snippet posted above I can't see why the test failed.

[sjsf]

Here is another, fresh one:

Tests run: 3, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 10.186 sec <<< FAILURE! - in org.eclipse.smarthome.binding.dmx.ArtnetBridgeHandlerTest
initializationOfBridgeHandler(org.eclipse.smarthome.binding.dmx.ArtnetBridgeHandlerTest)  Time elapsed: 10.082 sec  <<< FAILURE!
java.lang.AssertionError: 
Expected: is <ONLINE>
     but: was <OFFLINE>
    at org.hamcrest.MatcherAssert.assertThat(MatcherAssert.java:20)
    at org.junit.Assert.assertThat(Assert.java:956)
    at org.junit.Assert.assertThat(Assert.java:923)
    at org.eclipse.smarthome.binding.dmx.ArtnetBridgeHandlerTest.lambda$1(ArtnetBridgeHandlerTest.java:92)

Source: https://travis-ci.org/eclipse/smarthome/builds/328165836?utm_source=github_status&utm_medium=notification Build log: log.txt

[J-N-K]

From the log the test failed because the handler failed to open an outgoing UDP socket, so OFFLINE is the correct status. I‘ll add the error message from the exception, so we can see why it failed. Will be in the next version of the binding.

I never saw any of these tests failing in my local builds.

[sjsf]

Thanks for looking so quickly into this. I have no idea what they are doing on their infrastructure - sounds indeed weird. Let's just observe it until then. Here is another one for the gallery, but if they are troubling us too much because of infrastructure issues, then I would also be okay with disabling them.

[J-N-K]

After adding the additional debugging information I found a faulty logic in setting the thing status which in some cases (depending on timing) caused opening an already open socket. This is fixed now.