openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.88k stars 3.59k forks source link

Z-Wave Parameter Changes Lost #3169

Closed sercasyr closed 6 years ago

sercasyr commented 6 years ago

I am trying to change from openHAB 1.x to openHAB 2.2 and I have a very very critical issue that is stopping me from doing the migration.

With openHAB 1.x I was able to change the parameters of the Z-Wave devices by using HabMin. However, with openHAB 2.2 I have been unable to do it so far.

It seems very strange that an issue as important as this has been overlooked by so many people. Therefore, I wonder if I am doing something wrong...

Expected Behavior

I expect the parameters of the Z-Wave binding to remain after I shutdown the openHAB system and then, run it again.

Current Behavior

For what I have seen, if I change the parameters of a Z-Wave device (I do it with HabMin but I have tried also with PaperUI), they seem to be valid only within the current session of openHAB. If I close openHAB and then run openHAB again (or if I reset the PC in which it is running), the parameters go back to the default parameters. At least, this is what it is shown both in HabMin and PaperUI. Therefore I am never sure of the values of the parameters of my Z-Wave devices.

Possible Solution

Steps to Reproduce (for Bugs)

  1. Change the parameters of a Z-Wave Device
  2. Wait until they have been changed
  3. Check they are correctly shown in HabMin
  4. Close openHAB
  5. Run openHAB again
  6. Check the parameters of the Z-Wave device (in my case, they go back to default).

Context

Your Environment

I use openHAB 2.2, with Widows 10 with the latest version of the Z-Wave binding and HabMin (I have installed both from PaperUI). I have tried several different Z-Wave devices to be sure it is not a matter of the devices. In fact, the ones I have been lately using for debugging this issue are a not even battery operated to be sure also that it is not a question of wake-up periods.

I have tried so far 1 Aeon Labs MultiSensor 4 in 1 1 Aeon Labs MultiSensor 6 in 1 1 Aeon Labs LED RGB bulb

They behavior is the same for all of them...

There is no way I can see the parameters changed if I restart openHAB...

Please, help.

cdjackson commented 6 years ago

Please provide a detailed debug log showing the problem - without this it's difficult to help you I'm afraid.

sercasyr commented 6 years ago

HI Chris, How can I send you privately?

cdjackson commented 6 years ago

Best option is to open a ticket on my website (cd-jackson.com). You'll need to register, but you can then attach files etc and I can keep track of them (and it's private).

One question - how are you configuring your system? Is all configuration through the UI or are you using text files to configure things?

sercasyr commented 6 years ago

I think I've found a way. I've sent you via e-mail. Sorry if it is not the right choice.

Regarding the system, I've configured everything through the UI. In fact, my "system" right now is just a Z-Wave binding with just a Z-Wave controller and 5 devices. Nothing more.

The debug log corresponds to changing parameter 37 of a Light Bulb (Node 3), to a different value than the default one (30). Then I close openHAB and I run it again. Parameter 37 goes back again to 30. The light bulb is connected to mains so it should not suffer from battery issues.

cdjackson commented 6 years ago

Email is fine as well - no problem. The log however is not a debug log so there's no information I can use. We need to have debug logging enabled.

sercasyr commented 6 years ago

I launched start_debug.bat Isn't it enough?

cdjackson commented 6 years ago

No - this won't change anything with the logging. You need to explicitly enable debug logging with log:set debug org.openhab.binding.zwave

cdjackson commented 6 years ago

Fundimentally it looks ok -: image

The log here shows that the command was sent to the device, and the response from the GET shows that it was set correctly.

If I then look at the log to see the setting of the parameters back into ESH (which is what is then displayed in the UI) this also looks fine -:

2018-01-25 12:24:00.369 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Update CONFIGURATION 37/4 to 3840
2018-01-25 12:24:00.374 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Sub-parameter setting config_37_4_0000FF00 is 0000000F [15]
2018-01-25 12:24:00.376 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Sub-parameter setting config_37_4_00FF0000 is 00000000 [0]
2018-01-25 12:24:00.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 3: Sub-parameter setting config_37_4_7F000000 is 00000000 [0]

Based on this I can't see any problem. Maybe I'm looking at the wrong part of the log - please can you advise exactly what you were trying to do, at what time (so I can be sure I'm looking at the right part of the log) and what you see in the UI.

sercasyr commented 6 years ago

The operations I did are properly carried out, I think. The problem is that when I restart openHAB, the values of the parameters seem to be lost.

The last thing I did is to open HabMin and look at the parameters. I don't know if that is shown in the log.

I can perform a different kind of test if you recommend me something more meaningful.

Is it necessary to close openHAB with 'system:shutdown' and 'logout'??? I didn't do it, but in any case, I cannot be sure that there is not a power failure or an unxepected restart.

cdjackson commented 6 years ago

The last thing I did is to open HabMin and look at the parameters. I don't know if that is shown in the log.

No - we don't obviously see the UI information in the log. What is however shown in the log is the decoding of the parameters before they are set in the configuration properties. This is the part I've shown above - it looks fine to me. I'm not sure why this wouldn't then update in HABmin since the data is sent to ESH, and this is then provided through REST interface.

I can perform a different kind of test if you recommend me something more meaningful.

What you've done is fine - I can't think of anything else to check.

Is it necessary to close openHAB with 'system:shutdown' and 'logout'???

I'm not really sure what you're referring to here? If you mean do you need to shutdown before the UI gets updated, then no, you don't - the UI gets updated immediately the responses are received.

sercasyr commented 6 years ago

I'm not really sure what you're referring to here? If you mean do you need to shutdown before the UI
gets updated, then no, you don't - the UI gets updated immediately the responses are received.

I mean that if closing openHAB with 'system:shutdown' and 'logout' could have an effect in the behavior of the binding once it is started again.

Maybe something is not correctly written to a file and that could explain that if you close openHAB and then start it again, the values of the parameters are incorrectly shown

cdjackson commented 6 years ago

I mean that if closing openHAB with 'system:shutdown' and 'logout' could have an effect in the behavior of the binding once it is started again.

Ok, this is not required.

Maybe something is not correctly written to a file and that could explain that if you close openHAB and then start it again, the values of the parameters are incorrectly shown

That's pretty unlikely - the zwave binding doesn't save this data.

sercasyr commented 6 years ago

I have taken a look at the logs, and although I am not quite used to look into these log files, I think the information is wrong at the end.

At 12:23:34.414 the value is 30. This is ok. At 12:24:00.374 the value is 15. This is compatible with my action (it could've taken me 30 seconds to change it) At 12:24:35.772 the value is again 30 and the value 15 is apparently "lost". This is compatible with the time needed to shut the system and launch it again, and with what I see in the UI and in HABmin

2018-01-25 12:23:34.414 - NODE 3: Sub-parameter setting config_37_4_0000FF00 is 0000001E [30] 2018-01-25 12:24:00.374 - NODE 3: Sub-parameter setting config_37_4_0000FF00 is 0000000F [15] 2018-01-25 12:24:35.772 - NODE 3: Sub-parameter setting config_37_4_0000FF00 is 0000001E [30]

cdjackson commented 6 years ago

I'm getting quite confused about what problem you're reporting. The initial report is that it's not possible to send configuration parameters to the device. This clearly is not a problem (you agree, right?)

Now are you saying that everything works, but if you close down OH and restart, the values are not correct?

Please can you clarify the problem.

sercasyr commented 6 years ago

Sorry if I did not explain it clearly enough.

The problem is not that you can't set the parameters. The problem is that the values of the parameters seem to be lost when you restart openHAB and that is something that for me is a critical problem.

To summarize, the problem is that if you close down OH and restart, the values are not correct.

cdjackson commented 6 years ago

Ok, that was definately not so clear and I was not looking for this.

Please check the XML file to see what is saved there (in the userdata/zwave folder). This saves the state of the device, and it should always be correct. When the binding restarts, there is a synchronisation between the XML and the ESH view of the data - if the XML is somehow wrong, then this will be updated.

I assume you're not doing any other configuration between stopping and starting the system? ie you're not running OH1 between closing OH2 and then restarting it?

cdjackson commented 6 years ago

I also just realised we are discussing this in the wrong issue list (it should be the zwave issue list, not OH2).

sercasyr commented 6 years ago

I think that I also sent you the XML files. Anyway, I think the part of the XML (Node3.xml) that we should look is: ``

37
        <configurationParameter>
          <index>37</index>
          <size>4</size>
          <value>7680</value>
          <readOnly>false</readOnly>
          <writeOnly>false</writeOnly>
        </configurationParameter>
      </entry>

`` 7680 is not what I should expect. I don't know if it is encoded somehow, though.

I assume you're not doing any other configuration between stopping and starting the system? ie you're >not running OH1 between closing OH2 and then restarting it?

Not at all. I am testing this on a laptop with a clean new installation of OH2. There is no OH1, nor any other elements that could interfere.

cdjackson commented 6 years ago

Now that I understand your problem, I will also change my answer to your question about shutting down OH. The state that is saved in the XML file will not be saved if you don't close down the binding correctly. The binding saves the state periodically, and after it's done initialisation, but if you are shutting down without closing correctly, it won't be saved.

This is likely the problem as I don't see the saving messages in the log. It is saved at 12:23:44 after initialisation, then 12:24:54 after initialisation the second time. The binding was restarted at 12:24:29.

I think this explains the issue.

cdjackson commented 6 years ago

I propose you can close this. If the problem is not resolved by closing properly, then you will need to change to the latest development binding and we can deal with it there but I'm confident that it will be working in the development version.

sercasyr commented 6 years ago

It looks like if I close openHAB smoothly with system:shutdown and logout, the values are correctly shown when I restart OH2.

That explains the issue. However, I think it is still a problem because if I have an uxpected shutdown, I am not sure if the values I see are the correct ones or not when I restart OH.

I have several questions:

-How often does the binding save the state perodically?

-If the XML file is not saved/updated, the values shown in UI are the ones stored in the Z-Wave device? How can I be sure which values are the correct ones? I am confused

-If the values in the UI are incorrect, are these values immediately transferred to the device?

-What would be a solution for this?

cdjackson commented 6 years ago

The solution is the same as OH1 and you said it was ok there.

I don't propose to discuss this further here as it's just not the right place. I suggest that if you want to look at this further then it should be against the development version.

sercasyr commented 6 years ago

Ok. I'll close the issue, but I never had this problem with OH1, and it's been almost 4 years using it.

Maybe the way OH1 dealt with closing the console was different. I don't remember to have ever performed a system:shutdown or logout in OH1, and never noticed any parameter with a missing value.

Perhaps the solution is that OH2 captures the close signal and performs a system:shutdown so that bindings have the oportunity to close smoothly.

I'll try to post this topic in a different place (no idea where, if you give me a hint...)

Thanks

cdjackson commented 6 years ago

I don't really know why you are shutting down so often anyway. As far as I know the implementation in oH1 and oH2 is the same. The binding does cadaver the xml on bing shutdown but only if you are shutting down properly and I think you said you weren't doing this.

Sent from my iPhone

On 25 Jan 2018, at 15:04, sercasyr notifications@github.com wrote:

Ok. I'll close the issue, but I never had this problem with OH1, and it's been almost 4 years using it.

Maybe the way OH1 dealt with closing the console was different. I don't remember to have ever performed a system:shutdown or logout in OH1, and never noticed any parameter with a missing value.

Perhaps the solution is that OH2 captures the close signal and performs a system:shutdown so that bindings have the oportunity to close smoothly.

I'll try to post this topic in a different place (no idea where, if you give me a hint...)

Thanks

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

sercasyr commented 6 years ago

I shut down so often because my installation has many items, many bindings and with OH2 I get a lot of errors (it did not happen so often with OH1). From time to time, the system gets corrupted and I need to restart it.

This is the reason.