Zwave Thread Crashes on writeArray

[Grant Pitel]

Just got my new Gen5 Aeon ZStick but have not had any success getting it to run with OpenHAB 1.7.0 (Windows Server 2012 64bit).

For lack of a simple software, I installed InControl just to make sure my new purchase worked. It showed a couple devices and I was able to turn some lights on and off. I uninstalled when finished -- if anyone has a better recommendation for doing a sanity check please let me know.

It seems that the ZWave crashes on writeArray function and never releases the communications port. I have to restart openhab and power cycle my stick. I see read that zwave:softReset can cause problems with Gen5. That setting was not in my config file originally,soI set zwave:softReset=false, but still no luck.

The log lines that concern me are:

22:40:13.340 [ERROR] [WaveController$ZWaveSendThread:897 ] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
22:40:13.340 [DEBUG] [WaveController$ZWaveSendThread:942 ] - Stopped Z-Wave send thread
22:40:18.566 [DEBUG] [eController$ZWaveReceiveThread:1093 ] - Stopped Z-Wave receive thread
22:40:18.582 [INFO ] [b.z.i.protocol.ZWaveController:380 ] - Disconnected from serial port
22:40:18.582 [INFO ] [b.z.i.protocol.ZWaveController:299 ] - Connecting to serial port COM5
22:40:18.597 [ERROR] [b.z.i.protocol.ZWaveController:317 ] - Port COM5 in use.


The log in full is listed below:


22:40:07.067 [DEBUG] [.zwave.internal.ZWaveActivator:36 ] - Z-Wave binding has been started.
22:40:07.301 [INFO ] [.z.internal.ZWaveActiveBinding:301 ] - Update config, port = COM5
22:40:07.301 [INFO ] [.z.internal.ZWaveActiveBinding:306 ] - Update config, healtime = 2
22:40:07.301 [INFO ] [.service.AbstractActiveService:169 ] - ZWave Refresh Service has been started
22:40:07.301 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!
22:40:07.348 [INFO ] [b.z.i.protocol.ZWaveController:136 ] - Starting Z-Wave controller
22:40:07.363 [INFO ] [b.z.i.protocol.ZWaveController:141 ] - Z-Wave timeout is set to 5000ms.
22:40:07.363 [INFO ] [b.z.i.protocol.ZWaveController:299 ] - Connecting to serial port COM5
22:40:08.254 [DEBUG] [eController$ZWaveReceiveThread:998 ] - Starting Z-Wave receive thread
22:40:08.254 [INFO ] [b.z.i.protocol.ZWaveController:312 ] - Serial port is initialized
22:40:08.254 [DEBUG] [WaveController$ZWaveSendThread:855 ] - Starting Z-Wave send thread
22:40:08.270 [DEBUG] [o.b.z.i.protocol.SerialMessage:108 ] - NODE 255: Creating empty message of class = SerialApiSoftReset (0x08), type = Request (0x00)
22:40:08.270 [DEBUG] [o.b.z.i.protocol.SerialMessage:226 ] - Assembled message buffer = 01 03 00 08 F4
22:40:08.301 [DEBUG] [o.b.z.i.protocol.SerialMessage:108 ] - NODE 255: Creating empty message of class = GetVersion (0x15), type = Request (0x00)
22:40:08.301 [DEBUG] [b.z.i.protocol.ZWaveController:389 ] - Enqueueing message. Queue length = 1
22:40:08.301 [DEBUG] [WaveController$ZWaveSendThread:860 ] - Took message from queue for sending. Queue length = 0
22:40:08.301 [DEBUG] [o.b.z.i.protocol.SerialMessage:108 ] - NODE 255: Creating empty message of class = MemoryGetId (0x20), type = Request (0x00)
22:40:08.301 [DEBUG] [o.b.z.i.protocol.SerialMessage:226 ] - Assembled message buffer = 01 03 00 15 E9
22:40:08.301 [DEBUG] [b.z.i.protocol.ZWaveController:389 ] - Enqueueing message. Queue length = 1
22:40:08.301 [DEBUG] [WaveController$ZWaveSendThread:889 ] - Sending Message = 01 03 00 15 E9
22:40:08.301 [DEBUG] [o.b.z.i.protocol.SerialMessage:108 ] - NODE 255: Creating empty message of class = SerialApiGetCapabilities (0x07), type = Request (0x00)
22:40:08.301 [DEBUG] [b.z.i.protocol.ZWaveController:389 ] - Enqueueing message. Queue length = 2
22:40:08.301 [DEBUG] [i.p.s.GetSucNodeIdMessageClass:30 ] - Get SUC NodeID
22:40:08.301 [DEBUG] [o.b.z.i.protocol.SerialMessage:108 ] - NODE 255: Creating empty message of class = GetSucNodeId (0x56), type = Request (0x00)
22:40:08.301 [DEBUG] [b.z.i.protocol.ZWaveController:389 ] - Enqueueing message. Queue length = 3
22:40:12.311 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!
22:40:13.325 [ERROR] [WaveController$ZWaveSendThread:921 ] - NODE 255: Timeout while sending message. Requeueing
22:40:13.325 [DEBUG] [b.z.i.protocol.ZWaveController:389 ] - Enqueueing message. Queue length = 4
22:40:13.325 [DEBUG] [WaveController$ZWaveSendThread:860 ] - Took message from queue for sending. Queue length = 3
22:40:13.325 [DEBUG] [o.b.z.i.protocol.SerialMessage:226 ] - Assembled message buffer = 01 03 00 15 E9
22:40:13.325 [DEBUG] [WaveController$ZWaveSendThread:889 ] - Sending Message = 01 03 00 15 E9
22:40:13.340 [ERROR] [WaveController$ZWaveSendThread:897 ] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
22:40:13.340 [DEBUG] [WaveController$ZWaveSendThread:942 ] - Stopped Z-Wave send thread
22:40:17.318 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!
22:40:18.254 [WARN ] [veController$WatchDogTimerTask:1127 ] - Threads not alive, respawning
22:40:18.566 [DEBUG] [eController$ZWaveReceiveThread:1093 ] - Stopped Z-Wave receive thread
22:40:18.582 [INFO ] [b.z.i.protocol.ZWaveController:380 ] - Disconnected from serial port
22:40:18.582 [INFO ] [b.z.i.protocol.ZWaveController:299 ] - Connecting to serial port COM5
22:40:18.597 [ERROR] [b.z.i.protocol.ZWaveController:317 ] - Port COM5 in use.
22:40:18.597 [ERROR] [veController$WatchDogTimerTask:1132 ] - unable to restart Serial threads: Port COM5 in use.
22:40:22.326 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!
22:40:27.333 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!
22:40:32.341 [DEBUG] [.z.internal.ZWaveActiveBinding:98 ] - Zwave Network isn't ready yet!

[Chris Jackson]

I’ve never seen this before - it looks to me like some sort of problem with the serial port, or the driver, or something in the low level routines. What sort of hardware are you using?

[Grant Pitel]

I am using an Asus motherboard.   It was one of the first motherboards with 3.0 slots.... I will one of the 2.0 slots.

On Jul 19, 2015 3:43 AM, "Chris Jackson" <ch...@cd-jackson.com> wrote:

I’ve never seen this before - it looks to me like some sort of problem with the serial port, or the driver, or something in the low level routines. What sort of hardware are you using?

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/hXPmJpxspYo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.
To view this discussion on the web visit https://groups.google.com/d/msgid/openhab/2FEAFFCC-88C7-44AB-88F7-50F9AA5F8EB8%40cd-jackson.com.
For more options, visit https://groups.google.com/d/optout.

[Chris Jackson]

Ok, but what’s the processor - is this a PC? What about OS etc?

I’m not sure I’m going to be able to solve this - I suspect it might be some sort of incompatibility with the serial driver, but I’m not sure where to start looking for that. Are you able to debug?

[Grant Pitel]

My computer stats are listed below. I started up OpenHAB in debug mode.  Is there other ways I can debug the serial?

OS Name Microsoft Windows Server 2012 Standard

Version 6.2.9200 Build 9200

Other OS Description Not Available

OS Manufacturer Microsoft Corporation

System Name SKYNET

System Manufacturer System manufacturer

System Model System Product Name

System Type x64-based PC

System SKU To Be Filled By O.E.M.

Processor Intel(R) Core(TM) i7 CPU         920  @ 2.67GHz, 2668 Mhz, 4 Core(s), 8 Logical Processor(s)

BIOS Version/Date American Megatrends Inc. 2209, 9/21/2010

SMBIOS Version 2.5

Embedded Controller Version 255.255

BIOS Mode Legacy

BaseBoard Manufacturer ASUSTeK Computer INC.

BaseBoard Model Not Available

BaseBoard Name Base Board

Platform Role Desktop

Secure Boot State Unsupported

PCR7 Configuration Not Available

Windows Directory C:\Windows

System Directory C:\Windows\system32

Boot Device \Device\HarddiskVolume2

Locale United States

Hardware Abstraction Layer Version = "6.2.9200.16384"

User Name Not Available

Time Zone Eastern Daylight Time

Installed Physical Memory (RAM) 18.0 GB

Total Physical Memory 18.0 GB

Available Physical Memory 15.2 GB

Total Virtual Memory 20.5 GB

Available Virtual Memory 17.7 GB

Page File Space 2.50 GB

Page File C:\pagefile.sys

Hyper-V - VM Monitor Mode Extensions Yes

Hyper-V - Second Level Address Translation Extensions Yes

Hyper-V - Virtualization Enabled in Firmware Yes

Hyper-V - Data Execution Protection Yes

[Grant Pitel]

I think I have narrowed down the problem to a software issue and not a hardware issue.  I tried the same exact setup on a different computer.  A Window 8 32bit Atom Processor machine.  I am getting the same exact problem.  When I downloaded HABmin it contained a snapshot of z wave binding for (version 1.5) with the files below. 

org.openhab.io.habmin-1.5.0-SNAPSHOT.jar

org.openhab.binding.zwave-1.5.0-SNAPSHOT.jar

I wasvusing these in place of org.openhab.binding.zwave-1.7.0.jar figuring HABmin would work with only that version -- the install was not very specific on which to use.  

I just replaced it with 1.7 zwave binding and its not crashing anymore. I will keep you posted.  I also highlighted an error I was getting with 1.5 that was showing up only in the console. 

11:57:57.864 [DEBUG] [.z.internal.ZWaveActiveBinding:98   ] - Zwave Network isn't ready yet!

11:57:57.864 [INFO ] [b.z.i.protocol.ZWaveController:380  ] - Disconnected from serial port

11:57:57.864 [INFO ] [b.z.i.protocol.ZWaveController:299  ] - Connecting to serial port COM3

Error 0x2 at src/windows/termios.c(889): The system cannot find the file specif11:57:57.880 [ERROR] [b.z.i.protocol.ZWav

eController:317  ] - Port COM3 in use.

11:57:57.895 [ERROR] [veController$WatchDogTimerTask:1132 ] - unable to restart Serial threads: Port COM3 in use.

11:58:02.873 [DEBUG] [.z.internal.ZWaveActiveBinding:98   ] - Zwave Network isn't ready yet!

On Sunday, July 19, 2015 at 9:20:52 AM UTC-4, Chris Jackson wrote:

[Chris Jackson]

If the problem is the same on multiple computers, I’d suspect that it’s something you’re doing as Ive not heard this issue before.

Also, if you downloaded a version of HABmin that includes a 1.5 binding, then I’ve no idea where you got it from (the one on the HABmin website is 1.7), but I would suspect it’s at least 1 year old and I would suggest updating to the latest versions. You definitely shouldn’t use out of date versions as it will make it impossible to work out what you’re doing - please only use the latest versions.

The errors I’m seeing are all associated with the COM port driver - I’m not sure why this would only be happening with your configuration though...

[Grant Pitel]

Ok all good.   Up and running with zwave and OpenHAB!!!!   Using the bindings bundled with HABmin was the cause of my troubles.

[Grant Pitel]

Thanks for taking the time to answer my questions and giving me different ideas to try.

[Chris Jackson]

> On 19 Jul 2015, at 17:51, Grant Pitel <grant...@gmail.com> wrote:
>
> Ok all good. Up and running with zwave and OpenHAB!!!! Using the bindings bundled with HABmin was the cause of my troubles.

Ok - these binding should have worked fine, but there is a problem when downloading stuff from Github in that files are often corrupted… Anyway, at least you’re up and running :)