Does the controller show as online?
I guess there is a problem with zwave in combination with davis binding having the same serial port configuration. A hint for this is every 2 min = 120000 ms or 10 min = 600000 ms , refresh interval of davis binding. This could cause the problems. Please check both serial (zwave/davis) configurations.
A misconfiguration? A Z-Wave controller and a weather station cannot be connected to the same port.
Physically no, that is true. But you could give the virtual serial port of USB to both devices.
Technically, yes, you can specify the same port to both bindings, but they cannot interfere like this. The first one to start, and open the port should work, and continue to work, and the other one will fail.
1 Like
D-Link Smart Home Binding does not work in M5.
As far as I can see there have been no code changes to the binding code other than the build related files.
Both devices are mapped to its own ports:
lrwxrwxrwx 1 root root 7 Nov 21 19:41 /dev/vantage -> ttyUSB0
lrwxrwxrwx 1 root root 7 Nov 21 07:06 /dev/zwave -> ttyACM0
I deinstalled davis binding, but unfortunately the error remained, the controller is restarted every 2 Minutes. I’ll check serial config tonight
Did you set:
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"Hello,
I upgraded from M2 to M5, and got some problems with RFXcom binding.
I’m using the binding over tcp, and after a few hours, it kind of crash:
2019-11-22 06:03:20.768 [ERROR] [internal.handler.RFXComBridgeHandler] - Error occurred during packet receiving, data: 0AF2140100010253260000
org.openhab.binding.rfxcom.internal.exceptions.RFXComUnsupportedValueException: Unsupported value '-14' for PacketType
at org.openhab.binding.rfxcom.internal.messages.ByteEnumUtil.fromByte(ByteEnumUtil.java:37) ~[bundleFile:?]
at org.openhab.binding.rfxcom.internal.messages.RFXComMessageFactory.createMessage(RFXComMessageFactory.java:132) ~[bundleFile:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler$MessageListener.packetReceived(RFXComBridgeHandler.java:236) [bundleFile:?]
at org.openhab.binding.rfxcom.internal.connector.RFXComBaseConnector.sendMsgToListeners(RFXComBaseConnector.java:49) [bundleFile:?]
at org.openhab.binding.rfxcom.internal.connector.RFXComStreamReader.run(RFXComStreamReader.java:69) [bundleFile:?]
2019-11-22 06:03:21.170 [ERROR] [internal.handler.RFXComBridgeHandler] - Error occurred: Timeout during packet read
After running into this every 13 minutes, the full serial stack seems to crash and restart (as my zwave handler misteriously reconnect to the serial port):
2019-11-22 06:12:20.594 [INFO ] [nternal.connector.RFXComTcpConnector] - Connecting to RFXCOM at <Obfuscated_IP>:<Obfuscated_Port> over TCP/IP
2019-11-22 06:12:20.611 [ERROR] [internal.handler.RFXComBridgeHandler] - Connection to RFXCOM transceiver failed
java.lang.InterruptedException: sleep interrupted
at java.lang.Thread.sleep(Native Method) ~[?:1.8.0_232]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.connect(RFXComBridgeHandler.java:195) ~[?:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.lambda$0(RFXComBridgeHandler.java:162) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
2019-11-22 06:12:21.025 [INFO ] [nternal.connector.RFXComTcpConnector] - Connecting to RFXCOM at <Obfuscated_IP>:<Obfuscated_Port> over TCP/IP
2019-11-22 06:12:21.360 [ERROR] [internal.handler.RFXComBridgeHandler] - Connection to RFXCOM transceiver failed
java.net.SocketException: Relais brisé (pipe) (Write failed)
at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_232]
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) ~[?:1.8.0_232]
at java.net.SocketOutputStream.write(SocketOutputStream.java:143) ~[?:1.8.0_232]
at org.openhab.binding.rfxcom.internal.connector.RFXComTcpConnector.sendMessage(RFXComTcpConnector.java:97) ~[?:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.connect(RFXComBridgeHandler.java:200) ~[?:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.lambda$0(RFXComBridgeHandler.java:162) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
2019-11-22 06:12:22.329 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2019-11-22 06:12:22.397 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2019-11-22 06:12:22.419 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
Then, the handler is finally disposed and the thing stay UNINITIALIZED:
2019-11-22 06:14:20.756 [ERROR] [internal.handler.RFXComBridgeHandler] - Error occurred: Timeout during packet read
2019-11-22 06:14:21.053 [ERROR] [internal.handler.RFXComBridgeHandler] - Connection to RFXCOM transceiver failed
java.net.SocketException: Relais brisé (pipe) (Write failed)
at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_232]
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) ~[?:1.8.0_232]
at java.net.SocketOutputStream.write(SocketOutputStream.java:143) ~[?:1.8.0_232]
at org.openhab.binding.rfxcom.internal.connector.RFXComTcpConnector.sendMessage(RFXComTcpConnector.java:97) ~[?:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.connect(RFXComBridgeHandler.java:200) ~[?:?]
at org.openhab.binding.rfxcom.internal.handler.RFXComBridgeHandler.lambda$0(RFXComBridgeHandler.java:162) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
2019-11-22 06:14:26.001 [WARN ] [core.thing.internal.ThingManagerImpl] - Disposing handler for thing 'rfxcom:tcpbridge:70988158' takes more than 5000ms.
Any additional log or info i could share?
Have a nice day.
Edit: i had a openhab-misc-azureiothub that was saying it couldn’t be installed. I removed it as suggested by @Ingo_Bruland below in a similar situation. I will monitore it.
1 Like
Do they need to add their symlinks to that list too?
The only thing I know is this documentation.
and there:
sudo adduser openhab tty
.
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/ttyUSB0:/dev/ttyS0:/dev/ttyS2:/dev/ttyACM0:/dev/ttyAMA0"True, but using symbolic links is not in the official documentation.
In my opinion, they should try direct access without the symlinks, for troubleshooting purposes.
I’m coming from Stable 2.4. I updated, because I want to use an Fibaro Roller Shutter 3.
This device is listed as unknown in the 2.4. After some work on google most people said
that I have to update.
So this morning I started the upate from openhabian-config tool.
The update itsellf works fine. After the update the unknown device changed to Roller Shutter 
But after a look in the logs I saw the following:
2019-11-22 12:37:15.511 [hingStatusInfoChangedEvent] - 'zwave:device:3bd759e2:node7' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2019-11-22 12:37:15.515 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node8’ changed from ONLINE to UNINITIALIZED
==> /var/log/openhab2/openhab.log <==
2019-11-22 12:37:15.746 [WARN ] [.ZWaveThermostatSetpointCommandClass] - Reached max tries to init the setpont Furnace, this will be our last attempt
==> /var/log/openhab2/events.log <==
2019-11-22 12:37:15.780 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node8’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2019-11-22 12:37:15.784 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from ONLINE to UNINITIALIZED
==> /var/log/openhab2/openhab.log <==
2019-11-22 12:37:18.976 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
==> /var/log/openhab2/events.log <==
2019-11-22 12:37:19.073 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
==> /var/log/openhab2/openhab.log <==
2019-11-22 12:37:36.561 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing ‘openhab-action-mail’
2019-11-22 12:37:51.787 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
==> /var/log/openhab2/events.log <==
2019-11-22 12:37:52.308 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:52.438 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
==> /var/log/openhab2/openhab.log <==
2019-11-22 12:37:52.445 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port ‘/dev/ttyACM0’
2019-11-22 12:37:52.587 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-11-22 12:37:52.809 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-11-22 12:37:52.826 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
==> /var/log/openhab2/events.log <==
2019-11-22 12:37:53.129 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node7’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.146 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node10’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.155 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node2’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.217 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node10’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:37:53.221 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node7’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:37:53.225 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node11’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.242 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node8’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.258 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node6’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2019-11-22 12:37:53.287 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node2’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:37:53.324 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node8’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:37:53.341 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node6’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:37:53.345 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node11’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2019-11-22 12:38:11.015 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.054 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node2’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.072 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node11’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.084 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node7’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.114 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node10’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.124 [hingStatusInfoChangedEvent] - ‘zwave:device:3bd759e2:node6’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2019-11-22 12:38:11.159 [me.event.ThingUpdatedEvent] - Thing ‘zwave:serial_zstick:3bd759e2’ has been updated.
This goes round in a Loop: If everything is online, few seconfs later most things changed to offline, and again to online…
2019-11-22 12:36:54.175 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port ‘/dev/ttyACM0’
==> /var/log/openhab2/events.log <==
2019-11-22 12:36:54.180 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:3bd759e2’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
==> /var/log/openhab2/openhab.log <==
2019-11-22 12:36:54.259 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-11-22 12:36:54.418 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-11-22 12:36:54.420 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
Any Idea what happend?
If I change back to the old image, everything is fine.
Hi,
do you have other bindings installed? I see in your log that action mail failed installing.
I got a simmilar issue after changing to M5 with the Rest Documentation. It has been moved to another Addon category. After installing this again, then the reset/restart of zwave binding was gone.
Yes the mail action failed, but I reinstalled it and it stays the same. I can upload a log with the mail binding reinstalled. Actually I’m not at home. I will do. It in the evening
Anyone noticed MQTT errors?
2019-11-22 16:47:15.394 [ERROR] [ler.disconnect.MqttDisconnectHandler] - Exception while disconnecting.
java.lang.IllegalStateException: null
at com.hivemq.client.internal.util.collections.ChunkedArrayQueue$ChunkedArrayQueueIterator.remove(ChunkedArrayQueue.java:210) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingPublishService.drain(MqttIncomingPublishService.java:131) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingPublishService.onPublish(MqttIncomingPublishService.java:92) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingPublishService.onPublishQos0(MqttIncomingPublishService.java:65) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingQosHandler.readPublishQos0(MqttIncomingQosHandler.java:115) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingQosHandler.readPublish(MqttIncomingQosHandler.java:103) ~[?:?]
at com.hivemq.client.internal.mqtt.handler.publish.incoming.MqttIncomingQosHandler.channelRead(MqttIncomingQosHandler.java:92) ~[?:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) [bundleFile:4.1.42.Final]
at com.hivemq.client.internal.mqtt.handler.publish.outgoing.MqttOutgoingQosHandler.channelRead(MqttOutgoingQosHandler.java:317) [bundleFile:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) [bundleFile:4.1.42.Final]
at com.hivemq.client.internal.mqtt.handler.ping.MqttPingHandler.channelRead(MqttPingHandler.java:82) [bundleFile:?]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) [bundleFile:4.1.42.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:328) [bundleFile:4.1.42.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:315) [bundleFile:4.1.42.Final]
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:429) [bundleFile:4.1.42.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:283) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) [bundleFile:4.1.42.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) [bundleFile:4.1.42.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) [bundleFile:4.1.42.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:700) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:635) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:552) [bundleFile:4.1.42.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:514) [bundleFile:4.1.42.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044) [bundleFile:4.1.42.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [bundleFile:4.1.42.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [bundleFile:4.1.42.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2019-11-22 16:49:25.317 [ERROR] [b.handler.EspMilightHubBridgeHandler] - MQTT connection has been lost, cause reported is:{}
org.eclipse.paho.client.mqttv3.MqttException: Connection lost
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181) [org.eclipse.paho.client.mqttv3-1.2.0.jar:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: java.io.EOFException
at java.io.DataInputStream.readByte(DataInputStream.java:267) ~[?:1.8.0_222]
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:133) ~[?:?]
... 7 more
2019-11-22 16:57:38.916 [ERROR] [b.handler.EspMilightHubBridgeHandler] - Error: Could not connect to MQTT broker.{}
org.eclipse.paho.client.mqttv3.MqttException: MqttException
at org.eclipse.paho.client.mqttv3.internal.ExceptionHelper.createMqttException(ExceptionHelper.java:38) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms$ConnectBG.run(ClientComms.java:715) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_222]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: java.net.SocketTimeoutException
at java.net.SocksSocketImpl.remainingMillis(SocksSocketImpl.java:111) ~[?:1.8.0_222]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_222]
at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_222]
at org.eclipse.paho.client.mqttv3.internal.TCPNetworkModule.start(TCPNetworkModule.java:84) ~[?:?]
at org.eclipse.paho.client.mqttv3.internal.ClientComms$ConnectBG.run(ClientComms.java:701) ~[?:?]
... 7 more
2019-11-22 17:01:59.166 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1ed3c65' takes more than 5000ms.
2019-11-22 17:02:17.047 [ERROR] [ools.internal.NetworkUpsToolsBinding] - Nut processing error
java.net.SocketException: Broken pipe (Write failed)
at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_222]
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) ~[?:1.8.0_222]
at java.net.SocketOutputStream.write(SocketOutputStream.java:155) ~[?:1.8.0_222]
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221) ~[?:1.8.0_222]
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291) ~[?:1.8.0_222]
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:295) ~[?:1.8.0_222]
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141) ~[?:1.8.0_222]
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229) ~[?:1.8.0_222]
at org.networkupstools.jnut.StringLineSocket.write(StringLineSocket.java:118) ~[jNut-0.2-SNAPSHOT.jar:?]
at org.networkupstools.jnut.Client.get(Client.java:499) ~[jNut-0.2-SNAPSHOT.jar:?]
at org.networkupstools.jnut.Variable.getValue(Variable.java:78) ~[jNut-0.2-SNAPSHOT.jar:?]
at org.openhab.binding.networkupstools.internal.NetworkUpsToolsBinding.execute(NetworkUpsToolsBinding.java:107) [bundleFile:?]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:146) [bundleFile:?]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:169) [bundleFile:?]
2019-11-22 17:02:52.118 [WARN ] [com.zaxxer.hikari.pool.HikariPool ] - 5m47s698ms816μs393ns - Thread starvation or clock leap detected (housekeeper delta=yank-default).
Usually it first starts with errors like:
Dispatching event to subscriber '****' takes more than 5000ms.
CPU load is higher then normal. Between 100% and 300% vs 40-60%.
Almost no items receive updates.
Eventually the system most be rebooted
And from reading the link you posted to the other thread it appears it’s been broken since at least M3. I noticed Jan checked in your other thread but maybe create an issue on the appropriate github repo so developers are aware this binding is not functioning.
RFXcom binding seems to have some issues with serial port. I don’t use either binding so can’t confirm but again, maybe create an issue in the proper github repo.
Please post links to your git issues so all of us can play along at home.
Please remember to post what version you are upgrading from and what other bindings you are using
1 Like
hi @Celaeno1
yes it is set and I also addedthe symlinks just to be sure
EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/vantage:/dev/PBM:/dev/zwave:/dev/ttyACM0:/dev/IRLeser:/dev/ttyUSB0:/dev/ttyUSB1:/dev/ttyUSB2"
still the same, zwave restarts every minute now
Did you also “soft reset” the controller?
I did a soft reset an got then the following error:
2019-11-22 20:55:52.572 [WARN ] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
2019-11-22 20:56:04.602 [WARN ] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
2019-11-22 20:56:06.619 [WARN ] [ing.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
after a restart of OH2.5 M5 I’m getting again the errors:
2019-11-22 20:59:15.040 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-11-22 20:59:16.138 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2019-11-22 20:59:16.232 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave'
2019-11-22 20:59:16.279 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-11-22 20:59:16.302 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-11-22 20:59:16.302 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2019-11-22 21:00:14.920 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-11-22 21:00:16.035 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2019-11-22 21:00:16.141 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave'
2019-11-22 21:00:16.197 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-11-22 21:00:16.245 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-11-22 21:00:16.245 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.