Sometimes I see some errors in the logs, I have no clue what the problem is.
I don’t find any logic in time or something else causing the errors.
Does anyone have any idea?
2019-04-30 21:11:15.022 [ERROR] [s.handler.VelbusNetworkBridgeHandler] - Serial port write error
java.net.SocketException: Socket closed
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118) ~[?:?]
at java.net.SocketOutputStream.write(SocketOutputStream.java:143) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusNetworkBridgeHandler.writePacket(VelbusNetworkBridgeHandler.java:81) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.sendPacket(VelbusBridgeHandler.java:126) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.updateDate(VelbusBridgeHandler.java:90) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.updateDateTime(VelbusBridgeHandler.java:74) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.lambda$0(VelbusBridgeHandler.java:67) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-30 21:11:15.160 [ERROR] [s.handler.VelbusNetworkBridgeHandler] - Serial port write error
java.net.SocketException: Socket closed
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118) ~[?:?]
at java.net.SocketOutputStream.write(SocketOutputStream.java:143) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusNetworkBridgeHandler.writePacket(VelbusNetworkBridgeHandler.java:81) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.sendPacket(VelbusBridgeHandler.java:126) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.lambda$1(VelbusBridgeHandler.java:120) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2019-04-30 21:13:53.366 [ERROR] [s.handler.VelbusNetworkBridgeHandler] - Serial port write error
java.net.SocketException: Socket closed
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118) ~[?:?]
at java.net.SocketOutputStream.write(SocketOutputStream.java:143) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusNetworkBridgeHandler.writePacket(VelbusNetworkBridgeHandler.java:81) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusBridgeHandler.sendPacket(VelbusBridgeHandler.java:126) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusTemperatureSensorHandler.sendSensorReadoutRequest(VelbusTemperatureSensorHandler.java:103) ~[?:?]
at org.openhab.binding.velbus.handler.VelbusTemperatureSensorHandler.lambda$0(VelbusTemperatureSensorHandler.java:77) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
I access those logs with either “my-rpi-ip”:9001
Or when I PuTTy (is that Telnet?) to “my-rpi-ip”:22 , login and then use the command “openhab-cli showlogs”
@MDAR
I have no ID what “my-rpi-ip”:9001 shows, but when I compare that to the “openhab-cli showlogs”, to me it’s the same…
Interesting detail is that the 9001-version stays where you scroll the page, with the SSH-version it constantly flows
So both come handy
I was thinking the same…
At this moment I don’t see any errors, but as I said before, I couldn’t find any logic on why or when they appear. So, for now it’s ok.
If I see them again I’ll reply to this post
I’ve left my log viewer open all day today, I’ve been watching it for 8 hours (not constantly offcourse ).
And I’m happy to say that I haven’t seen a single error message like the ones I’ve posted here. let’s hope it stays like this. But I’ve got a good feeling about it…
A “java.net.SocketException: Socket closed” exception can happen in various situations. Either the server side closed the connection like nKn suggested, or the client side (your app) closed the connection. Even if you are not aware of doing it, there may be some less obvious code that may lead to closing the socket, like Thread.interrupt() or ExecutorService.shutdownNow().
Hi, quincybatten1 is right, it looks like the network connection got interrupted somehow. Most likely the server isn’t listening anymore (e.g. a machine going into standby mode, restarting, …). A bad Wifi signal could also result in this kind of problems. Unfortunately the openHab velbus binding doesn’t restore connections once they fail, that will be something to improve in a next version.
First message in this forum: I want to thanks everyone for the good work. I used a lot the information shared by @MDAR and @cedricb in various topic both on Openhab and Velbus forum.
I have a similar issue as in the initial message in this thread. My socket connection is lost. I figured out this is due to my daily (nightly btw) reboot of the raspberry pi located closed to my electric panel with velserv installed.
My openhab server is located elsewhere but lose the ability to drive the velbus bus due to the reboot. The only way I have been able to reconnect is to restart the full openhab service on my server. I would like to find an alternative solution, it is possible to only restart a binding ? or ask to reconnect the binding every x seconds / min / hour ?
The suggested auto-reconnect is of course very appealing to me but I am sure this is representing quite some work.
Are you running Cédric’s latest version? Which has a reconnect routine built in. If this isn’t working, please report it to Cédric.
(I think the issue listed currently is actually more to do with the link between the two parts of VelServ, rather than Cédric’s binding)
If you’re using PaperUI for your things, you can simply disable, wait, enable the Velbus Network Thing. Which will restore the connection
You can go into Karaf and completely restart the Velbus binding. bundle:restart {number of binding}
The real question is…
Why do you need to restart your RPi every day?
Can you just restart a faulty app and leave VelServ running?
Alternatively, it looks like you can schedule a restart of a binding from an openHAB2 rule
Yes I am running the latest version of the binding: Feb2020. In Karaf, I have a bundle version of 2.4.0.201901161113. I used your update script.
I am looking for an automated way to restart the binding so the PaperUI is not a viable solution for me. However, this is good to know we can restart it manually and easily that way.
Same story for the Karaf method.
I know that restarting the RPi every day is not a good starting point. I have several services linked to my very heterogeneous home automation system. I really do not know which one is causing my issue forcing me to reboot every day. To be honest, the issue is happening randomly once every two weeks, which makes it very difficult to analyse and investigate… But I definitively think you are right, I should not have to restart this RPi from the beginning. However, I would feel more confortable that my system can afford a restart of this component once in a while.
I am looking at your alternative solution referring to the openHAB community post. Seems not super easy but well explained so I should be able to make it.
May I ask you (or anyone to be honest), if you restart the velserv service or reboot the device supporting the velserv service, do you also lose the connection through the binding ?
I’ll drop that into the zip file that my script pulls down later today.
If I stop VelServ (on the same machine as openHAB2) it almost instantly makes the Velbus Network Bridge go offline.
(Or the bridge goes offline when I try to use a Velbus Item)
Likewise, when I start VelServ again, the bridge either instantly comes back online, or as soon as I try to use a Velbus Item the status gets updated.
(I might have to command the Velbus Item a second time to get a reaction from the Velbus device)
In summary, I’m happy that the binding is recovering from a network failure.
Maybe this is something the Cédric has fine tuned recently.
Hello,
I was not fluent with GitHub way of downloading… I downloaded and installed the latest release and everything seems to work “properly” now. At least it is much more error proof and allow me to restart velserv server.
Many thanks for the excellent work from Cedric and super support from you ;o)
I have implemented the restart binding button based on the slightly different post on the openhab community last night but I think this is not relevant anymore (except for my learning curve).
I have made some additional tests and it seems my problem is not yet solved, unfortunately.
After rebooting my network device running the velserv connection with the velbus bus, I have the following error when requesting an update:
I would expect the binding to understand the connection needs to be restarted after 15sec (default reconnect option). However, after waiting a few more seconds, I request again a new change on the bus and I have a slightly different error:
java.net.SocketException: Socket closed
any subsequent request will end up with the same error.
The same story happens if I “simply” restart the velserv service on my network device. This is why I am puzzled with MDAR’s test. I have double checked that the binding installed is the most recent one. I have uninstalled it, restarted the server and reinstalled it. Installation seems clean on this side. I have done the same for each Thing (I have an USB bridge and 2 vmb6pbn).
Could it be to some specifics of my system ?
I would like to help you to help me the best way I can, so do not hesitate to ask me any specific files / log / command.
).
let’s hope it stays like this. But I’ve got a good feeling about it…