Reconnect to Ethernet Gateway after Inactive Session

[RB3rg]

I see that if the Ethernet Gateway is restarted the telnet session from the binding still up and won't try to reconnect. Is there any option to reconnect after a silence time?

[andreacioni]

Hi RB3rg, I'm currently working on how to solve this type of problem. Soon or later this feature will be availbabe to all :)

[andreacioni]

This should be closed :)

[tobof]

Implemented! :-)

[glmnet]

This seems not to be working on my RPI, I'm running a manifest Bundle-Version: 2.0.0.201701181308 Using RPI MySensors Gateway Ethernet running locally, if I do restart the mysgw service, then OpenHAB communication with MySensors stops working and it recovers when I restart the OpenHAB service.

[andreacioni]

Thanks for reporting the issue. Could you provide an extract of your logs?

[glmnet]

So this is basically what I get when restarting waiting a while and trying to command a light. Let's say 17:45:50.587 is the last message received before restarting mysgw I'm copying this from log:tail in karaf

17:45:35.609 [INFO ] [marthome.event.ItemStateChangedEvent] - NivelLuz_Comedor changed from 69 to 70 17:45:40.613 [INFO ] [marthome.event.ItemStateChangedEvent] - Humedad_Comedor changed from 66.3 to 66.2 17:45:45.594 [INFO ] [marthome.event.ItemStateChangedEvent] - NivelLuz_Comedor changed from 70 to 71 17:45:50.587 [INFO ] [marthome.event.ItemStateChangedEvent] - Humedad_Comedor changed from 66.2 to 66.3 17:48:04.501 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on AireEstado_Comedor 17:48:04.504 [ERROR] [kit.internal.HomekitAccessoryUpdater] - Received duplicate subscription on AireEstado_Comedor 17:48:05.284 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Luz_Comedor_Techo' received command ON 17:48:05.294 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from OFF to ON 17:48:06.050 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Luz_Comedor_Techo' received command OFF 17:48:06.062 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from ON to OFF 17:48:09.453 [WARN ] [rs.internal.protocol.MySensorsWriter] - NO ACK from nodeId: 1 17:48:10.155 [WARN ] [rs.internal.protocol.MySensorsWriter] - NO ACK from nodeId: 1 17:48:10.162 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from OFF to ON 17:48:12.533 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Luz_Comedor_Techo' received command OFF 17:48:12.542 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from ON to OFF 17:48:13.358 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'Luz_Comedor_Techo' received command ON 17:48:13.364 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from OFF to ON 17:48:16.963 [WARN ] [rs.internal.protocol.MySensorsWriter] - NO ACK from nodeId: 1 17:48:17.263 [WARN ] [rs.internal.protocol.MySensorsWriter] - NO ACK from nodeId: 1 17:48:17.271 [INFO ] [marthome.event.ItemStateChangedEvent] - Luz_Comedor_Techo changed from ON to OFF

[glmnet]

I am wondering if all this is related to the fact that I am running everything from files, things and items files. Looks like it can reconnect after it refreshes my things file.. 18:23:55.077 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'demo.things' 18:23:55.101 [INFO ] [al.protocol.ip.MySensorsIpConnection] - Successfully connected to MySensors Bridge. 18:23:55.102 [WARN ] [al.protocol.ip.MySensorsIpConnection] - Network Sanity Checker thread disabled from bridge configuration 18:23:55.121 [INFO ] [smarthome.event.ThingRemovedEvent ] - Thing 'mysensors:light:gateway:light_dicro_comedor' has been removed. 18:23:55.165 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'astro:sun:home' has been updated. 18:23:55.252 [ERROR] [rs.internal.protocol.MySensorsWriter] - (java.lang.InterruptedException) on writing to connection, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorsIpWriter 18:23:55.257 [ERROR] [rs.internal.protocol.MySensorsReader] - (java.lang.InterruptedException: sleep interrupted) on reading from connection, message: class org.openhab.binding.mysensors.internal.protocol.ip.MySensorIpReader 18:23:55.264 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:bridge-eth:gateway' has been updated. 18:23:55.270 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:light_comedor' has been updated. 18:23:55.275 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:light_exterior' has been updated. 18:23:55.283 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:light_dicro_living' has been updated. 18:23:55.295 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:motion:gateway:pir_comedor' has been updated. 18:23:55.306 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:humidity:gateway:humedad_comedor' has been updated. 18:23:55.310 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:temperature:gateway:temperature_comedor' has been updated. 18:23:55.315 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:door_principal' has been updated. 18:23:55.320 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:switch_comedor' has been updated. 18:23:55.324 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:switch_doorbell' has been updated. 18:23:55.332 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:hvacThermostat:gateway:hvact_comedor' has been updated. 18:23:55.338 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light-level:gateway:ldr_comedor' has been updated. 18:23:55.342 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:customSensor:gateway:info_comedor' has been updated. 18:23:55.345 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:switch_dicro_comedor' has been updated. 18:23:55.352 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:light1_dormi1' has been updated. 18:23:55.357 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:light2_dormi1' has been updated. 18:23:55.363 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:dicro1_dormi1' has been updated. 18:23:55.369 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light:gateway:dicro2_dormi1' has been updated. 18:23:55.374 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:motion:gateway:pir_dormi1' has been updated. 18:23:55.379 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:humidity:gateway:humedad_dormi1' has been updated. 18:23:55.383 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:temperature:gateway:temperature_dormi1' has been updated. 18:23:55.387 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:door_dormi1' has been updated. 18:23:55.391 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:door:gateway:switch_dormi1' has been updated. 18:23:55.398 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:hvacThermostat:gateway:hvact_dormi1' has been updated. 18:23:55.402 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:light-level:gateway:ldr_dormi1' has been updated. 18:23:55.406 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:customSensor:gateway:info_dormi1' has been updated. 18:23:55.411 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'mysensors:customSensor:gateway:ir_dormi1' has been updated. 18:23:55.471 [INFO ] [al.protocol.ip.MySensorsIpConnection] - Successfully connected to MySensors Bridge. 18:23:55.472 [WARN ] [al.protocol.ip.MySensorsIpConnection] - Network Sanity Checker thread disabled from bridge configuration 18:23:55.643 [ERROR] [ersey.server.ServerRuntime$Responder] - Error while committing the output stream. org.eclipse.jetty.io.EofException at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:192)[72:org.eclipse.jetty.io:9.2.19.v20160908] at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:408)[72:org.eclipse.jetty.io:9.2.19.v20160908] at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:302)[72:org.eclipse.jetty.io:9.2.19.v20160908] at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:129)[72:org.eclipse.jetty.io:9.2.19.v20160908] at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:697)[80:org.eclipse.jetty.server:9.2.19.v20160908] at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:246)[83:org.eclipse.jetty.util:9.2.19.v20160908]

[andreacioni]

No files aren't the problem. This is probably a bug in the binding. At this time the only check we do is send a message and waiting for a response. If no answer to this message is received within 3/4 seconds we disconnect bridge (I see from log you have disabled this feature, but it will not solve your problem).

The best thing to do by now is to manage, also, exception in Reader & Writer both. I hope to integrate this feature in the refactoring that we are doing.

[glmnet]

How did I disabled it? This is how it looks now in things file Bridge mysensors:bridge-eth:gateway [ ipAddress="127.0.0.1", tcpPort=5003, sendDelay=200 ] { ... things ... }

[andreacioni]

It is disabled by default. If you want change it, you could add in Bridge configuration this: enableNetworkSanCheck=true I see it is not documented in the binding Wiki 😉 we must update it.

[tobof]

I've documented the feature in the wiki.