ZWave binding updates

Hello!

What happens with a fresh install (edit: of openHAB)?

Silly question, but are the device drivers installed on Windows?

An OH backup and restore would not change the Windows drivers.

True. but I have no idea how to relate unstable snapshot numbers to testing and stable releases.
The user said they copied the whole OH folder but did not state whether OH was running at that time. Copying the folder can be different from a backup. I do not have experience with OH on Windows to help much on that.

From the first post, it works after restoring the backup.

I say we eliminate the upgrade aspect. I may just boot over to windows and try my backup zwave controller, since there are some other things I could test in Windows.

2 Likes

From my research, snapshot 1460 is before 2.5M1, I believe and well before the huge changes in Milestone 2. The OH serial drivers used by the zwave binding changed in that time, I believe.

It might be worth trying the zstick connected to a usb2 hub. If you have it connected to a usb3 port, the stick says it can support usb3 when it cannot. This was the issue with the Pi 4. I do not know how using a different Java serial driver enters into this though.

Of course Iā€™ve stopped OH before making a copy. Since all OH files in Windows version are located inside of OH folder, copying that folder equals backup. And it works when I delete updated OH folder and restore the one I made copy of. I have latest Z-stick S2 drivers installed (itā€™s gen2 stick in my case, not gen5).

Best regards,
Davor

2 Likes

Thank you davorf for testing and patience and also reporting in critical issues thread. I believe this is an important issue to try to resolve before stable release. Thank you also Scott for windows testing

1 Like

The ESH reintegration started at S1566.

Could you please try a fresh installation to eliminate a potential upgrade issue? But before that, could you verify that there is nothing in your /conf/addons/ directory?

Hello!

Itā€™s too late to do it right now. Hope Iā€™ll catch some free time tomorrow to try with a fresh install. Iā€™ve checked addons folder and, besides readme, thereā€™s no other files in it.

Best regards,
Davor

got last night on openHAB 2.5.0 Build # 1776 update offline / online problem is gone
But I have Openhabian on Raspberry3

1 Like

@davorf I have had similar issues upgrading to M5, but because of travels and lots of thing to do, I had to go back to M4, but hopefully Iā€™ll find some time tomorrow to test newer builds.
Maybe #1776 fixes something if not RC1.

Just to say you are not alone, and that Iā€™m following your progress. :slight_smile:

Edit: Iā€™m on linux, and are using Aeon Gen5 stick.

1 Like

@vespaman Micael thank you for reporting, we are now up to 5 folks with this issue.
Please report your issue in this thread:

Please include details about what operating system and platform you are using, the fact rolling back to M4 fixed it and also any binding you use that also use the serial connection

I would like to ask everyone reporting issues to report exactly what issue THEY have. I want to really be sure that issues are the same and not jump to any conclusions. Itā€™s easy to say that issues people see are the same, and they may have the same or similar appearance, but we need full visibility.

From my perspective, there have not been any code changes that could impact this - there was only one very minor change in this time. Below is a list of changes (excluding database changes) since M4.

From what Iā€™ve seen in the log referenced above by @davorf -:

Error 0x6 at src/windows/termios.c(512): The handle is invalid.

this looks like a problem with serial drivers in the system. I donā€™t know if there have been any changes to the serial driver - as best as I can tell the last change was in 2018 - or anything else that could impact this.

The error is not quite the same as the following issue on GH, but itā€™s similar -:

There are other reports of issues in Win10 with these sort of errors.

This is the change I am suspect of Chris where to find more about this change. Do I understand correctly that OpenHAB now uses an ā€˜embeddedā€™ serial driver and that the zwave binding uses a newer serial driver to access that embedded serial driver??? How can I find more info about this change?
I do remember a conversation on github where Kia asked you about doing something similar and you were reluctant to make that change at that time because you were busy with other stuff. Seems like around the time the IDE wasnā€™t worling. Iā€™ll try to find thread on github

At the lower levels, the serial driver is the same (I believe) as 2.4 - itā€™s just the way that the ZWave binding interacts with the driver is now through an openHAB proxy layer.

The change was made in April - so 8 months ago and definately not related to the M4 to M5 that is reported here since M4 was released in late September I believe.

I suspect you are getting this mixed up with something else since the serial change was made in April and the IDE issues were later.

1 Like

For reference (from Jenkins):
September 7 Milestone 3
October 19 Milestone 4
November 17 Milestone 5
December 1 Milestone 6
December 9 Release Candidate 1

OK, so today I finally had some time to test RC1.
I got exactly the same issue with it as M5.

Hereā€™s a log snippet that might help us; It happens afaict about every minute, and makes every node change state.

10:47:08.591 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 101: TID 355: Timeout at state WAIT_DATA. 3 retries remaining.
10:47:08.591 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 355: Transaction CANCELLED
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: notifyTransactionResponse TID:355 CANCELLED
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
10:47:08.592 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 12 02 87 02 25 CB 9E 
10:47:08.591 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 355: Transaction event listener: DONE: CANCELLED -> 
10:47:08.592 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 18: Sending REQUEST Message = 01 09 00 13 12 02 87 02 25 CB 9E 
10:47:08.592 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
10:47:08.592 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 356: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 203
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: Node Init response (4) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@7748ca4e
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: No data from device, but it was ACK'd. Possibly not supported? (Try 4)
10:47:08.592 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: Node Init transaction retries exceeded
10:47:08.592 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: SECURITY not supported
10:47:08.592 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: Command Class COMMAND_CLASS_METER is NOT required to be secured
10:47:08.593 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 101: ZWaveCommandClassTransactionPayload - send to node
10:47:08.593 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: SECURITY not supported
10:47:08.593 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 101: Command Class COMMAND_CLASS_METER is NOT required to be secured
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@148a93b2
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: Adding to device queue
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 101: Added 359 to queue - size 50
10:47:08.593 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:47:10.132 [INFO ] [ding.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
10:47:10.133 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Interrupted taking message from recvQueue
java.lang.InterruptedException: null
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) ~[?:1.8.0_202]
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048) ~[?:1.8.0_202]
        at java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:403) ~[?:1.8.0_202]
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:440) [bundleFile:?]
10:47:10.136 [DEBUG] [zwave.discovery.ZWaveDiscoveryService] - ZWave discovery: Deactivate zwave:serial_zstick:controller
10:47:10.144 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
10:47:10.145 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
10:47:10.147 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:controller' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:47:10.164 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from OFFLINE (COMMUNICATION_ERROR): Opening SDCP connection failed: Ingen vƤg till vƤrd (Host unreachable) to UNINITIALIZED
10:47:10.167 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:47:10.427 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
10:47:10.442 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'sonyprojector:ethernetconnection:a2ba257e' changed from INITIALIZING to UNKNOWN

I should perhaps also mention that I had one (in my opinion) very strange issue when going from 2.4 to M4, as reported here.
I know it might be a faulty node, but suggestions around serial drivers made me think it might be related.

From a quick look, this is totally different to what was being discussed earlier which was a USB issue with an exception being thrown in the serial driver.

This is why itā€™s always best to post information like this, and not just the ā€œI have the same problemā€ statements.

Please provide the debug log so I can take a look.