Binding seems to loose connection

[dereulenspiegel]

In the past days I'm seeing the following messages a lot in my logs

Cannot read data from MAX!Cube lan gateway while connecting to 'null'

It seems that the bindings "forgets" the host to which to connect to.

[marcelrv]

I've seen similar messages. This was when I moved over from the old version of the binding to the new version of the binding. Now I restarted with debug I can't reproduce the error message, at least not more than once.

Do think there iss till something strange in the sense that I have the feeling the updating already starts prior to the binding being fully loaded. e.g. here's my startup you can see the first 2 reads are done prior to the discover/config reading

12:11:06.354 DEBUG o.o.b.m.i.MaxCubeActivator[:30] - MAX!Cube LAN gateway binding has been started. 12:11:06.852 INFO o.o.c.s.AbstractActiveService[:169] - MAX!Cube Refresh Service has been started 12:11:06.880 INFO o.o.b.m.i.MaxCubeBinding[:248] - Cannot read data from MAX!Cube lan gateway while connecting to 'null' 12:11:06.916 TRACE o.o.b.m.i.MaxCubeDiscover[:72] - Request packet sent to: 192.168.3.255; Interface: eth0 12:11:06.932 TRACE o.o.b.m.i.MaxCubeDiscover[:76] - Done looping over all network interfaces. Now waiting for a reply! 12:11:06.924 DEBUG o.o.b.m.i.MaxCubeBinding[:249] - java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:585) at java.net.Socket.connect(Socket.java:534) at java.net.Socket.(Socket.java:430) at java.net.Socket.(Socket.java:211) at org.openhab.binding.maxcube.internal.MaxCubeBinding.execute(MaxCubeBinding.java:114) at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173)

12:11:07.613 TRACE o.o.b.m.i.MaxCubeDiscover[:88] - Broadcast response from server: /192.168.3.9 12:11:07.620 DEBUG o.o.b.m.i.MaxCubeDiscover[:98] - Found at: 192.168.3.9 12:11:07.624 DEBUG o.o.b.m.i.MaxCubeDiscover[:99] - Name : eQ3MaxAp 12:11:07.629 DEBUG o.o.b.m.i.MaxCubeDiscover[:100] - Serial : KEQ056000 12:11:07.633 TRACE o.o.b.m.i.MaxCubeDiscover[:101] - Message : eQ3MaxApKEQ0560000>I YQ 12:11:07.638 INFO o.o.b.m.i.MaxCubeBinding[:375] - Discovered MAX!Cube lan gateway at '192.168.3.9'

[aheil]

I experienced the same behavior but did not pay attention to this issue yet. @marcelrv, this fix works quite well. @dereulenspiegel can you confirm this happens only at start up time or does this also happen after some time openHAB runs this binding? I can't see any execution path that could change the ip of the cube without the configuration being changed. If this issue can be monitored at runtime, please let me know, we than might add additional debug information to trace back when the binding forgets about the cube.

[aheil]

I now run a test for 3 hours. I did readings every 10 seconds from the cube and did not loose the connection a single time. It seems quite stable at the current state.

[marcelrv]

I guess the better way to solve this is by not setting the setProperlyConfigured(true) right away, but only set it to true after the configuration is done. Have not tested this yet though...

public void activate() {
    super.activate();
    setProperlyConfigured(true);
}

[dereulenspiegel]

With the latest revision I now receive the following message:

14:27:15.826 DEBUG o.o.b.m.i.MaxCubeBinding[:112]- Update prior to completion of interface IP configuration

[marcelrv]

@dereulenspiegel

Do you have anything configured in your openhab.cfg wrt to MaxCubeBinding? Do you see anything related to the discovery. As if no IP is configured, it should do the discovery process, if IP is configured it should use that (and can't be null) and it should behave as before.

The only way I can see this happening if somehow the public void updated(Dictionary config) throws ConfigurationException { which takes care of the configuration is not run at all (which according to the documentation is always called so would be something strange indeed.)

can you show the other debug messages you get wrt to the maxcube during the startup

[aheil]

Hi all, I've merged everything from @marcelrv. For me the discovery works quite fine as well as the latest fix. For the moment I was not able to reproduce any startup without the IP being .