openhab / org.openhab.binding.zwave

openHAB binding for Z-Wave
Eclipse Public License 2.0
170 stars 202 forks source link

Z-Wave binding resets configuration of serial port to /dev/ttyACM0 #1059

Closed Tymo3 closed 5 years ago

Tymo3 commented 5 years ago

OH2 Version: 2.4 M5 (same with ZWave binding)

Just to avoid changes of USB name (ACM0, AMA0, ...) I have set up link /dev/zwave_stick described here (https://rolfblijleven.blogspot.com/2015/02/howto-persistent-device-names-on.html#steps) I have added it to EXTRA_JAVA_OPTS in /etc/default/openhab2 --> EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zwave_stick"

After clean start ZWave binding tries to connect to /dev/ttyACM0 (which is ok). But after changing in PaperUI zwave stick configuration to /dev/zwave_stick is shows in logs changes, but then during thing searching it again changes to /dev/ttyACM0.

openhab.log 2018-11-10 09:38:39.678 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:38:39.705 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2018-11-10 09:39:44.904 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:39:44.921 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave_stick' 2018-11-10 09:39:44.936 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2018-11-10 09:39:44.941 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller 2018-11-10 09:39:44.943 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2018-11-10 09:39:44.964 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 20: Not initialized (ie node unknown), ignoring message. 2018-11-10 09:40:25.388 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:40:25.416 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2018-11-10 09:40:27.449 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService$1.run(ZWaveDiscoveryService.java:83) ~[?:?] 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) [?:?]

cdjackson commented 5 years ago

If you change the configuration of the stick, then the binding will reinitialise - this is not a bug.

On 10 Nov 2018, at 10:34, Tymo3 notifications@github.com wrote:

OH2 Version: 2.4 M5 (same with ZWave binding)

Just to avoid changes of USB name (ACM0, AMA0, ...) I have set up link /dev/zwave_stick described here (https://rolfblijleven.blogspot.com/2015/02/howto-persistent-device-names-on.html#steps https://rolfblijleven.blogspot.com/2015/02/howto-persistent-device-names-on.html#steps) I have added it to EXTRA_JAVA_OPTS in /etc/default/openhab2 --> EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zwave_stick"

After clean start ZWave binding tries to connect to /dev/ttyACM0 (which is ok). But after changing in PaperUI zwave stick configuration to /dev/zwave_stick is shows in logs changes, but then during thing searching it again changes to /dev/ttyACM0.

openhab.log 2018-11-10 09:38:39.678 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:38:39.705 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2018-11-10 09:39:44.904 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:39:44.921 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave_stick' 2018-11-10 09:39:44.936 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized 2018-11-10 09:39:44.941 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller 2018-11-10 09:39:44.943 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false. 2018-11-10 09:39:44.964 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 20: Not initialized (ie node unknown), ignoring message. 2018-11-10 09:40:25.388 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler 2018-11-10 09:40:25.416 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0' 2018-11-10 09:40:27.449 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: java.lang.NullPointerException: null at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService$1.run(ZWaveDiscoveryService.java:83) ~[?:?] 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) [?:?]

After changing /etc/default/openhab2 to EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zwave_stick:/dev/ttyACM0:/dev/ttyAMA0" it worked but ZWave does not recoginze any of elements [...] 2018-11-10 09:55:27.624 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:512:node35' to inbox. 2018-11-10 09:55:27.630 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 36: Device discovery could not resolve to a thingType! Manufacturer data not known. 2018-11-10 09:55:27.640 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:512:node36' to inbox. 2018-11-10 09:55:27.646 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 39: Device discovery could not resolve to a thingType! Manufacturer data not known. 2018-11-10 09:55:27.656 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:512:node39' to inbox. 2018-11-10 09:55:27.662 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 40: Device discovery could not resolve to a thingType! Manufacturer data not known. 2018-11-10 09:55:27.672 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:512:node40' to inbox. 2018-11-10 09:55:27.678 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 53: Device discovery could not resolve to a thingType! Manufacturer data not known. [...]

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/openhab/org.openhab.binding.zwave/issues/1059, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_kQxzZwR02P61So1K0hePmLRHoxHUSks5utqu0gaJpZM4YX7c4.

Tymo3 commented 5 years ago

ok, maybe I made it not clear

how I did it: setup /dev/zwave_stick (as permanent link) then clean install of openhab, 2.4.0~M5 then Zwave binding installed from PaperUI then go to control panel to update thing Z-Wave stick after chaging it to /dev/zwave_stick (as it was /dev/ACM0) it shows in logs that is changed then go to PaperUI, Inbox, search for z-wave devices and then it changes automatically to /dev/ACM0

t

cdjackson commented 5 years ago

I don’t really understand this - what is control panel for starters? Please can you be clear on what the issue actually is, what you have done, and provide debug logs if at all possible. To me it looks like you have changed the port, and it has changed, so it’s really unclear - sorry.

On 10 Nov 2018, at 10:48, Tymo3 notifications@github.com wrote:

ok, maybe I made it not clear

how I did it: setup /dev/zwave_stick (as permanent link) then clean install of openhab, 2.4.0~M5 then Zwave binding installed from PaperUI then go to control panel to update thing Z-Wave stick after chaging it to /dev/zwave_stick (as it was /dev/ACM0) it shows in logs that is changed then go to PaperUI, Inbox, search for z-wave devices and then it changes automatically to /dev/ACM0

t

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/openhab/org.openhab.binding.zwave/issues/1059#issuecomment-437575159, or mute the thread https://github.com/notifications/unsubscribe-auth/AA_kQ5jiYN6eNx6yCBuxbzoTqulJ00koks5utq8bgaJpZM4YX7c4.

Tymo3 commented 5 years ago

ok - making it more clear (I hope)

I have tried also in Habmin (and same result as from PaperUI), So, in Habmin:

  1. I changed port for ZWave USB Dongle in Habmin pannel (Configuration->Things->Zwave dongle->Port configuration->/dev/zwave_stick)
  2. Save (in logs I can see change of port to /dev/zwave_stick)
  3. Then click on Zwave discovery (zoom icon, then select Zwave binding) (in logs I can see change of port to /dev/ttyACM0) - it was when I was not changing anyting configuration, GUI or whatsoever
  4. Just to be sure I went to habmin and open ZWave USB Dongle, and in port configuration is again "/dev/ttyACM0"

take a look on part of log starting from 2018-11-10 12:11:38.421 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave_stick'

included openhab.log openhab.zip

manuelmuehlig commented 5 years ago

Hi, exactly this is my problem too. After restarting OpenHab the binding defaults to /dev/ttyUSB0, which is wrong in my case. I always have to reset it after the startup to /dev/zwave in PaperUI.

bodiroga commented 5 years ago

Hi @cdjackson and all!

I would say that this is related to https://github.com/openhab/org.openhab.binding.zigbee/issues/307

What do you think @hsudbrock? The USBDiscoveryService is updating the Thing serial port with the default one ("/dev/ttyUSB0"), overwriting the one provided by the user ("/dev/zwave" or what the user has written in the udev rule). Does it make sense to you?

cdjackson commented 5 years ago

@bodiroga I'm wondering if we shouldn't revert the USB discovery for now? This is probably the biggest issue we've got at the moment and it's been causing a lot of problems. Given 2.4 is about to be released in a week or two, I think it might be worth removing it until after 2.4 is released, otherwise we will have to live with these problems in 2.4 for the next 6 months.

WDYT? Unless there's a clear fix in the coming days I think it should be reverted...

hsudbrock commented 5 years ago

Do I understand you correctly that the issue is that the config of an existing thing which was created via discovery is overwritten?

If yes: This could be due to an ESH feature that exists independently of the USB discovery: If a discovery result has the same thing Uid as an existing thing, then ESH will update the config of the existing thing with the one from the discovery result.

Or is your issue that the discovery result uses another port than desired? If yes: What is the issue with the port selected by the discovery? Is it not working and why?

Am 2. Dezember 2018 19:08:28 MEZ schrieb Aitor Iturrioz notifications@github.com:

Hi @cdjackson and all!

I would say that this is related to https://github.com/openhab/org.openhab.binding.zigbee/issues/307

What do you think @hsudbrock? The USBDiscoveryService is updating the Thing serial port with the default one ("/dev/ttyUSB0"), overwriting the one provided by the user ("/dev/zwave" or what the user has written in the udev rule). Does it make sense to you?

-- You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub: https://github.com/openhab/org.openhab.binding.zwave/issues/1059#issuecomment-443528662

-- Diese Nachricht wurde von meinem Android-Gerät mit K-9 Mail gesendet.

bodiroga commented 5 years ago

Hi everyone!

@hsudbrock I'm not suffering from this problem, but after reading @manuelmuehlig's and @Tymo3's report I thought that it could be related. Guys, how did you first create the Z-Wave controller thing? By hand or using the USB Discovery service? Could you tell us what is the ThingID of your USB stick? 512?

@cdjackson You are totally right, we should revert the USB discovery because it is a nightmare :disappointed: Not having a unique serial number in the USB controller is a pain in the ass (and as you have pointed out many times, reading the network ID is very risky), because we can't be sure if the discovered device is the same as the previous one. Go ahead and revert the commit for 2.4 release :+1:

manuelmuehlig commented 5 years ago

@bodiroga I tried both ways of creating the thing. By searching in the inbox and by manually adding it. No difference. My thing ID is zwave:serial_zstick:0001 . After every restart of Openhab the serial port gets reset and I have to manually change it to /dev/zwave. Interestingly in PaperUI this is also the only available choice in the port configuration.

cdjackson commented 5 years ago

Thanks @bodiroga. If you have time, can you provide a PR to revert the USB discovery? Thanks.

Tymo3 commented 5 years ago

@bodiroga - same as @manuelmuehlig I tried both ways. My thing ID is _zwave:serialzstick:512

bodiroga commented 5 years ago

Hi again!

My thing ID is zwave:serial_zstick:0001

@manuelmuehlig, what type of Z-Wave controller are you using? An Aeon Labs Z-Stick Gen2? Or do you have created, by hand, the "serial_zstick:0001" Thing ID?

Thanks @bodiroga. If you have time, can you provide a PR to revert the USB discovery? Thanks.

Ok @cdjackson , I will provide a PR to revert the changes, although I'm not sure if I can use any GitHub tool. Anyway, I will create a new branch, delete de USB discovery implementation and submit it :wink:

@bodiroga - same as @manuelmuehlig I tried both ways. My thing ID is zwave:serial_zstick:512

The "serial_zstick:512" thing ID indicates that you are using the autodiscovered Z-Wave controller. @hsudbrock, I'm pretty sure that what we are seeing here is the first case you described: the framework is updating a Thing with the same Thing ID. But, the problem is that the USB discovery service is not able to see that "/dev/zwave" is linked to "/dev/ttyUSB0", so it thinks that the port has changed and overwrites the configuration specified by the user. And, as far as I know, that's the same thing described by @puzzle-star in https://github.com/openhab/org.openhab.binding.zigbee/issues/307. While the USB discovery service is active, we shouldn't recommend using any udev rule, because the service should handle any port change ("/dev/ttyUSB0" to "/dev/ttyUSB1", for example).

In any case, @manuelmuehlig and @Tymo3, even if the port changes in Paper UI everytime you restart openHAB, doesn't the controller work as expected? In fact, "/dev/ttyUSB0" is a valid port, so I don't understand why it shouldn't work. The thing controller appears as offline? "Port already in use" error? In @Tymo3's log file it can be seen that the Z-Wave network is correctly initialized.

Sorry for my late reply and thanks for your fast answers!

Best regards,

Aitor

manuelmuehlig commented 5 years ago

Ok here is more info from my side. I have an Aeon Labs Z-stick S2 which is linked to ttyUSB0, however I have an udev rule to create a link /dev/zwave, since I have multiple USB/Serial devices and the order could change. In /etc/default/openhab2 I have added the line EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zwave". Otherwise openhab cannot communicate with the device, right? After restarting Openhab it tries to use port ttyUSB0: [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyUSB0'

which fails with [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:0001' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Serial Error: Port {0} does not exist The same message is visible in PaperUI. After changing there to /dev/zwave which is also the only option everything works:

[ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/zwave' [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized [ve.internal.protocol.ZWaveController] - Starting ZWave controller [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.

bodiroga commented 5 years ago

Hi @manuelmuehlig!

I have an Aeon Labs Z-stick S2 which is linked to ttyUSB0

Great, my assumption was correct then!

In /etc/default/openhab2 I have added the line EXTRA_JAVA_OPTS="-Dgnu.io.rxtx.SerialPorts=/dev/zwave". Otherwise openhab cannot communicate with the device, right?

Absolutely correct, as "/dev/zwave" is no a common port, openHAB doesn't have access to it unless you explicitly indicate it.

[hingStatusInfoChangedEvent] - 'zwave:serial_zstick:0001' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to OFFLINE (COMMUNICATION_ERROR): Serial Error: Port {0} does not exist

I can't understand why openHAB doesn't see the "/dev/ttyUSB0" port :confused: It is a default port name, so it shouldn't be necessary to specify it in "/etc/default/openhab2", really confusing... Manuel, what user is openHAB 2 running on? "openhab"? is the "openhab" user part of dialout and tty groups? You can check it with the following command "groups openhab". openHABian automatically adds "openhab" user to tty, dialout, audio, bluetooth and gpio groups, but I don't know if you are using it.

Anyway, I have already created the PR to remove the USB discover participant from the binding, so the next stable version of the binding will no have this problem (nor the feature :disappointed:)

Thanks for your help!

Aitor

manuelmuehlig commented 5 years ago

Manuel, what user is openHAB 2 running on? "openhab"? is the "openhab" user part of dialout and tty groups? You can check it with the following command "groups openhab". openHABian automatically adds "openhab" user to tty, dialout, audio, bluetooth and gpio groups, but I don't know if you are using it.

Yes user is openhab, groups are "openhab tty dialout". I have a debian system running in a QNAP virtual machine (Linux home 4.9.0-7-amd64 #1 SMP Debian 4.9.110-1 (2018-07-05) x86_64 GNU/Linux). The installed version is: ii openhab2 2.4.0~S1447-1 all openhab2

puzzle-star commented 5 years ago

I commented the same on the ZigBee implementation.

nrjavaserial implementation should be discovering ttyUSBx devices without the need to be added to gnu.io.rxtx.SerialPorts, but it seems no to be doing so under OH.

I will try to figure out why, as the functionality of discovering the devices is superb, so it is a pity to lose it because something that should work off-the-shelf from nrjavaserial is not behaving as expected

cdjackson commented 5 years ago

USB discovery was removed from the binding before 2.4 was released.