OH2 Z-Wave refactoring and testing... and SECURITY

Agreed!! Chris has put a great amount of effort - so much I’m sure there are pieces of his soul in that code!! :grinning:

I made sure after my first ticket to go submit some coffees to the pool for the endless hours of sleep lost due to minor changes hear and there when we find em!

Thank you @chris as always for the hard work - and patience with some of us! :wink:

1 Like

It’s done. Thanks for providing the place to do it.
Chris, thank you for your hard work! Have a beer on me!

1 Like

Thanks everyone. Beer is always good - although I normally try and put donations towards “toys” so hopefully it helps me improve things in the longer term :slight_smile: .

1 Like

Chris am I correct in understanding you are aware of issues with alarm reporting? I’ve currently got 2 issues, a 4in1 multisensor that has it’s alarms ignored pretty much and a door lock which seems to throw exceptions with it’s alarms. If you need another log file let me know and I’ll submit at your site.

Yep - I’m aware of this and will take a look over the next few days.

Does anyone else experience a zwave crash from a few hours to a few days after starting the binding? As reported here? It seems to occur more often with debug logging on. I am also getting a lot of missed events (OH says lights, motion, etc. are on/off, but not correctly). I’m becoming suspicious of my g5 zstick, which has been solid for quite a long while and this all started after moving to OH2 and the dev zwave binding months ago. I’d like to confirm others are experiencing either of these and confirm it’s not just my hardware before troubleshooting further and possibly opening an issue.

Or maybe Chris is aware of something that could be causing this?

No - I would guess that one of your devices is sending a message that is not handled properly. As mentioned earlier, it would be good to get a log capturing this if possible?

I had sent one to your email address… I’ve resent in case it didn’t get through…

That was for the crash… I haven’t noticed anything in the log for the missed events. They either don’t come in at all (ie, manually turning off a light or switch with Hail or motion is detected/not detected), or OH shows a state change but the lights don’t actually turn on/off. I’ll get you a log for this. It happens often.

It’s best to open a ticket on my website - it’s much easier to track and things don’t go into the spam folder (or just get lost).

Can you provide a log that shows the event? At the moment you’ve sent me a reasonably long log, but nothing is logged for this ‘crash’ and I’ve no idea what I’m looking for. Ideally I’d like to see the received messages in the second or two before the event otherwise I’m kind of searching for the good old needle in the haystack…

I guess this is the known problem about notifications that has been discussed above? I will look at this issue tomorrow.

Chris,
Please go back to my original post and let me know if that gives you a starting point. That post includes the exception from the log (with timestamp) that I believe is related to the error in the console. Next time I’ll post on your site instead of email.

I don’t think the missed event issue could be related to the notification issue, since not all of the devices affected use the Alarm CC. And notifications appear to be working in the version of binding that I’m currently using. But I’ll table this one and see if it gets corrected in the next update.

Yes - I already looked at this, but this isn’t of much use. Ideally I’d like to see the received messages in the second or two before the event otherwise I’m kind of searching for the good old needle in the haystack…

Ok, well you’ll need to provide concrete examples then. If this is the case, I’ll need a log showing the incoming data, and the fact that it doesn’t get processed. Or at least something more to go on…

I’m not quite following since you have the log file and the timestamp of the exception :confused:… but I’ve opened a ticket (C8RnqWkhvY3) and included the portion of the log 2s prior to the exception. It looks to me like the last event before the exception was about 3min before it occurred.

Ok, sorry, where is that then :confused:? It’s definitely not in the log you emailed me - that log only has 1 exception, and it’s not the same as the one above -:

2017-06-01 00:30:11.810 [Handler$ZWaveReceiveThread] - Exception during ZWave thread. 
java.lang.IllegalStateException: Queue full

Sorry if I’m missing something, but I get a lot of emails, github requests, PMs, and forum messages every day and it’s not easy to try and correlate different information in different places, or logs that don’t tie up. It may seem like I’m being difficult, but I can spend really a lot of time trying to correlate all these things so I’d just like to be clear.

I’ve just looked at the log you sent on the ticket, and again, this is a different exception that you posted in the link above which is what I’ve been looking for. In the link above, the exception is -:

java.lang.reflect.InvocationTargetException

and in your logs it’s -:

java.lang.IllegalStateException: Queue full

Sorry - but I’m also confused now - the exceptions are very different and I wanted to see a log from the first one you raised. Do you have this? Or am I just missing the point completely :slight_smile: .

Yes, this is a terrible way to track issues! Probably best for me to be opening issues for these on Github so all the info can be tracked in one place. As far as coming across as being difficult, I almost said the same in regards to my own posts! It’s easy for me to leave off the personal touch while immersed in the technical. You’re doing the impossible here and I completely understand getting stuff done with a million irons in the fire. No offense taken, and hopefully none given. Your efforts are VERY much appreciated!

For this issue, this may be the piece that’s alluding you :thinking::

Yes - this is actually why I started the ticket system given here we are often looking at security. I didn’t want to have to ask people to post logs with secure information onto github. Some people don’t mind, but there’s a risk if you post these logs with secure information, someone can break into your network as it would not be too hard to crack the keys.

No - it’s not eluding me, but I need to see the information from this event. I asked to get a log relating to this event and you’ve sent a log with another exception - hence the confusion. I’ve no way to correlate this with the karaf console.

You said -:

So from this can I assume that they are happening at the same time? I’d be a bit surprised if this was the case, but is this your point as to why I have the information with the logs you’ve provided?

I don’t think this is the case since the exception you want me to look at from the console says it occurs in the alarm command class, while the log only appears to show meter messages.

Somehow we need to find the messages that are occurring when this exception happens. Maybe I need to improve the logging somewhere - it’s a bit annoying that some messages seem to only go to the console and don’t end up in the logs. I wonder if there’s a log configuration setting that can change this…

Thanks :slight_smile: .

I have zwave devices no longer responding before the stack trace comes through in the console. I have a rule that notifies me when one of the energy monitors has not reported for 3 minutes. From the log, it looks like the exception comes in a few minutes after the energy monitor stops reporting. The console trace and log exception appear to be related, but I can’t say for certain that they happen simultaneously.

I thought you were meaning that you were not finding the exception in the log file. But you had the timestamp, so I did not understand what more information you would need… or that I could provide.

I also think I should clarify that it is the second stack trace that correlates to the exception in the log file:[quote=“5iver, post:1009, topic:21653”]
Exception in thread “Thread-43” java.lang.ArrayIndexOutOfBoundsException: 0
[/quote]

It’s interesting if these two exceptions are related - that might also make sense. The first one likely stops processing of the recieved packets, and then the second one (the queue full exception) that’s in the log is probably caused by messages not being processed due to the first exception screwing up the processor.

I need to spend some time looking at the issue with alarms this afternoon. I’ll take a look at trying to add something to better catch the exceptions and log them in the log rather than karaf console. If I can do this we can hopefully get a nice clean log that avoids my current confusion :thumbsup:.

@shadowmite and others who have reported issues with notifications not working. I just did a test here and it seems to work fine (using a Sensative Strips). In the logs I’ve seen from someone, there was really nothing at all being logged from the command class, and this all looks ok here.

So, I’ll create an update tonight and let’s see if it’s working - if not, send me a log and we’ll take another look.

@5iver I’ve also added some code to try and catch all exceptions in command classes that aren’t already caught. Let’s see if that helps get everything logged in one place ;).