Good point - I’ll change it, but I don’t think it will change anything though. If that was the problem then there would be an error logged (ie an exception when it tried to convert the value). Let’s see though…
Yeah, I was hesitant to even bring it up, because I figured it would log an error.
Otherwise, I’m at a loss to explain what’s happening.
Nah - definitely should bring it up as it’s a bug (not in the test - in the code), but I would still expect an error / exception to be thrown.
Agreed. I guess we’ll see what happens with the next build…
I’ve just triggered a build since I think auto builds are currently broken…
Ok. I’ll try it out as soon as the build finishes.
Some things were built, but it doesn’t look like the zwave binding was built.
Yes, it was built ok in the bundles repository - the build no longer uses the zwave repository… The system is now using submodules to combine the repositories - what I’m not sure of is how to work out what version of the ZWave binding has been built - I suspect it’s not updated though.
Ah, thanks, I didn’t realize that. I’ll try it now.
Now on last nights build.
ID | State | Lvl | Version | Symbolic name
----------------------------------------------------------------------
178 | Installed | 80 | 2.0.0.201609130942 | org.openhab.binding.zwave
There you go. That was it.
I have no idea why it wasn’t throwing an exception. Normally, wouldn’t an illegal cast be picked up by the compiler? I suppose the runtime behavior is unpredictable.
016-09-13 07:00:19.374 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Configuration update received 2016-09-13 07:00:19.382 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Configuration update wakeup_interval to 600.0 2016-09-13 07:00:19.383 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Set wakeup interval to '600' 2016-09-13 07:00:19.383 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Creating new message for application command WAKE_UP_INTERVAL_SET to 600 2016-09-13 07:00:19.383 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 06 06 84 04 00 02 58 01 00 00 3A 2016-09-13 07:00:19.383 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Sending REQUEST Message = 01 0D 00 13 06 06 84 04 00 02 58 01 00 00 3A 2016-09-13 07:00:19.383 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Putting message SendData in wakeup queue. 2016-09-13 07:00:19.384 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Creating new message for application command WAKE_UP_INTERVAL_GET 2016-09-13 07:00:19.384 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 6: Putting message SendData in wakeup queue.
Thanks for helping me work through this. Now I can get back to the original problem. 
It’s not an illegal cast - it’s casting an object wince the configuration can be a number of different types (TEXT/INTEGER/STRING), so you should get an exception at runtime.
Anyway, I’m glad it’s working .
Here’s the log file and my assessment.
https://drive.google.com/open?id=0Bwmcwu6ccTd_RkhUaWllRF9JV1E
Starting at 06:58:04.030
- node 6 sends two unsolicited sensor_multi_level_reports
- two seconds later the binding sends the wake_up_interval_set
Why does the binding send a wake_up_interval_set? I thought battery devices were only awake after they issued a wake_up_notification.
Note that the above activity occurs before node 6 is fully initialized.
Starting at 07:11:27.651
- node 6 is awake
- node 6 is fully initialized (i.e. node.xml created)
- sends wake_up_interval_set and wake_up_interval_get
- sends sensor_get on EP1; device responds with temperature. EP1 is defined as temperature in the database
- sends sensor_get on EP2; device responds with humidity. EP2 is defined as humidity in the database
This all looks good to me unless you see something wrong.
Starting at 07:20:19.175
- node 6 is awake
Uneventful. This activity continues every 10 or so minutes.
Starting at 07:26:44.749
- node 6 sends sensor_multi_level_reports
Uneventful. This activity continues every 10 or so minutes.
Starting at 08:13:27.989
- node 6 is awake
- sends sensor_multi_level_get for temp; device responds with humidity
- sends sensor_multi_level_get for humidity; device responds with temp
- sends battery_get; device responds with temp
- sends sensor_get on EP1 (temp); device responds with humidity
- sends sensor_get on EP2 (humidity); device responds with temp
My theory is that the sensor_multilevel_gets are causing the device to get confused.
What would be the effect of removing the sensor_multilevel database entries on EP0? Will the unsolicited sensor_multi_level_reports still be handled correctly?
The message isn’t sent - it’s put into the wakeup queue -:
NODE 6: Sending REQUEST Message = 01 0D 00 13 06 06 84 04 00 02 58 01 00 00 3A
NODE 6: Putting message SendData in wakeup queue.
This is correct - the logging incorrectly shows that this is sent though.
Why at this time (ie 08:13:27)? It does the same thing earlier (07:59:55).
The requests at 08:13 are the first ones (I think) that request the types - I’m not sure why at the moment - I’d need to dig deeper into the log.
Probably not - they are sent to EP0, so if they are removed, then we probably stop the reports. Would probably be better to remove the multi channel version…
That’s node 5 at 7:59:55. I believe 8:13:27 is the first occurrence for node 6.
Ok, I don’t think that changes things though. Even at 08:13, before the multi_instance messages, it’s sending the wrong responses (unless I missed one earlier, but I think you said this was the first time the multi channel requests are sent?).
I think it’s either mis-handling the requests that request a specific sensor, or it’s ignoring them (which I guess is basically the same! 
).
Yes, I think we’re saying the same thing.
8:13:27 is the first time a sensor_multi_level_get is sent, and the device responds incorrectly to that request AND to subsequent requests for battery and multi_instance.
Contrast that to earlier at 7:11:27 when battery and multi_instance work correctly (and sensor_multi_level_gets were not sent).
Wait. I see what you’re saying. The earlier multi_instance ones don’t have a type.
Yep. Even before the multi_instance message is sent, it’s already responding incorrectly (at 08:13).
Who knows what’s up - it’s not exactly clear except that the device never seems to respond correctly to the sensor requests (so it seems).
The question of “does this stop the battery requests” is another one that I don’t think is answered in this log (maybe we need a bit more time).
I pulled some stats from my logs this morning for all battery-powered nodes. This is after more than 24 hours of runtime. I’m showing the following stats:
- frequency of WAKE_UP_NOTIFICATIONs
- frequency of BATTERY_GETs
- frequency of BATTERY value responses
Nodes 2, 5, 6, & 7 all are ST-814s. Node 2 is running firmware version 2.1. Nodes 5, 6, & 7 are running version 1.6.
Node WAKE_UP BATTERY_GET BATTERY 2 33 59 27 3 29 58 28 4 22 59 22 5 33 59 2 6 42 56 2 7 32 58 2 12 28 60 28 23 30 59 30 24 14 60 14 28 29 54 54 35 26 49 21
Clearly, 5, 6, and 7 are not getting battery reports other than at initial startup when the sensor_multi_level_get call is made without the sensor type. Interestingly, node 2 is getting battery reports. I assume that’s because it is running a newer firmware version than 5, 6, and 7, and, while it’s behaving differently, it’s still behaving badly.
I skimmed the spec this morning, and it looks like sensor-type is not part of the sensor_multi_level_get message for versions less than 5 (these devices are version 2 – at least that’s what the database and node.xml says). Would that be why the device is mishandling the request when the request includes sensor-type?
Who knows, but you’re right, this is a bug. It’s something that’s identified in the source - I guess it was always written this way an I didn’t want to remove it, but now we have the proper specs, I think it’s safe…
I’ll update shortly.