Force initial brightness flakey

Hi,

Since mid '22 I am running a rule that sets param19 depending on the time of day (as shared in Zwave Force initial brightness won't accept 100 as command - #8 by mvandamn). This worked like a charm until recently, where the set value does not reliably seems to stick.
If set, it sometimes sticks, and sometimes reverts back to the previous value when polled.

In the logs that looks like this:

2024-01-25 22:30:00.342 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'ToiletLight_ForceInitialBrightness' received command 20
2024-01-25 22:30:00.345 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 10
2024-01-25 22:30:00.348 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'BathroomCeilingLight_ForceInitialBrightness' received command 15
2024-01-25 22:30:00.349 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'ToiletLight_ForceInitialBrightness' predicted to become 20
2024-01-25 22:30:00.350 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'ToiletLight_ForceInitialBrightness' updated to 20
2024-01-25 22:30:00.350 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ToiletLight_ForceInitialBrightness' changed from 65 to 20
2024-01-25 22:30:00.350 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 10
2024-01-25 22:30:00.351 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 10
2024-01-25 22:30:00.351 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 10
2024-01-25 22:30:00.352 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'BathroomCeilingLight_ForceInitialBrightness' predicted to become 15
2024-01-25 22:30:00.352 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' updated to 15
2024-01-25 22:30:00.352 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' changed from 99 to 15
2024-01-25 22:45:42.797 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 22:45:42.798 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 10 to 35
2024-01-25 22:46:59.804 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' updated to 45
2024-01-25 22:47:43.250 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 22:48:56.494 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 22:49:00.534 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' updated to 45
2024-01-25 22:49:00.613 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' updated to 45
2024-01-25 22:49:11.677 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'ToiletLight_ForceInitialBrightness' updated to 65
2024-01-25 22:49:11.677 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ToiletLight_ForceInitialBrightness' changed from 20 to 65
2024-01-25 22:50:03.806 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 22:51:43.509 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'ToiletLight_ForceInitialBrightness' updated to 65
2024-01-25 22:51:53.513 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'ToiletLight_ForceInitialBrightness' updated to 65
2024-01-25 23:14:01.214 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 23:14:23.490 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' updated to 45
2024-01-25 23:14:47.345 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 23:27:13.536 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 23:28:10.945 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 23:34:50.427 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' updated to 45
2024-01-25 23:34:51.543 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 35
2024-01-25 23:35:42.415 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' updated to 99
2024-01-25 23:35:42.415 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' changed from 15 to 99

I can’t really track down to when this behavior started, if this was with the 4.0 upgrade, 4.1, or some patch in between.

When I now try to send a value manually from the CLI, it does seem to stick.

openhab> openhab:status HallwayLight_ForceInitialBrightness
35
openhab> openhab:send HallwayLight_ForceInitialBrightness 85
Command has been sent successfully.
2024-01-26 12:17:28.544 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 85
2024-01-26 12:17:28.546 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 85
2024-01-26 12:17:28.547 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 85
2024-01-26 12:17:28.547 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 85
2024-01-26 12:17:28.619 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 85
2024-01-26 12:17:30.091 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 85

2024-01-26 12:21:48.372 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'HallwayLight_ForceInitialBrightness' updated to 85

side note: since 4.0 I see a lot more ‘updates’ in the event log, whereas it used to only log changed values, it now seems to log every value that is polled.

Any ideas on how to troubleshoot this would be welcome!

^ Marcus

https://community.openhab.org/t/openhab-4-0-1-and-ipcamera/148319/2?u=sihui

Thanks, that takes are of the side-note :slight_smile:

I had never changed that file, nor did it prompt me about it during the upgrade. But I’ll sync it manually now.

You have autoupdate enabled on the Item (it’s the default). Autoupdate predicts what state it thinks the Item is going to become based on command and updates the Item accordingly. However, if the device fails to change as a result of the command or autoupdate predicted the wrong state, the next time the device reports it’s state the Item will change to match the device’s actual reported state.

So when it reverts, what is really happening is the device either isn’t receiving the command or the command is failing in some other way.

You can disable autoupdate through the Item metadata.

Building on the autoupdate comment: There is a lack of polling after the command is sent in the “flaky” example. Note that in the CLI example there is an update at 1.5 seconds after the command (SET). This is the binding polling (GET) (at the command poll interval at the bottom of the device UI page) and the device responding with a REPORT.

Will not be able to diagnose why without a Zwave debug. One thing to check which was recently found to affect polling (although maybe not in your case) was the presence of orphan links (openhab:links orphan list/purge)

Thanks for the explanation about auto-update @rlkoshak, so it would make sense to me to assume that the device did not properly receive (or save) the setting, and therefore on the next poll return the old value.

Meanwhile I changed the log4j2.xml to quite things down a bit, which makes troubleshooting easier.

I checked, and there were a ton of orphans, most of them seem to be from the early days of setting up the lights. I purged those. And have openHAB a restart.

Unfortunately this did result into improvement.

2024-01-26 16:46:01.494 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'KitchenLight_ForceInitialBrightness' changed from NULL to 0.0
2024-01-26 16:46:01.921 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from NULL to 85.0
2024-01-26 16:46:01.981 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BalconyLight_ForceInitialBrightness' changed from NULL to 35.0
2024-01-26 16:46:02.032 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'DiningAreaLight_ForceInitialBrightness' changed from NULL to 0.0
2024-01-26 16:46:02.098 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' changed from NULL to 45.0
2024-01-26 16:46:02.349 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BedroomCeilingLight_ForceInitialBrightness' changed from NULL to 0.0
2024-01-26 16:46:03.456 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ToiletLight_ForceInitialBrightness' changed from NULL to 65.0
2024-01-26 16:46:03.771 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' changed from NULL to 99.0
2024-01-26 16:57:00.174 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'OfficeCeilingLight_ForceInitialBrightness' received command 5.0
2024-01-26 16:57:00.176 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'OfficeCeilingLight_ForceInitialBrightness' predicted to become 5.0
2024-01-26 16:57:00.177 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' changed from 45.0 to 5.0
2024-01-26 16:57:00.182 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 35.0
2024-01-26 16:57:00.183 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 35.0
2024-01-26 16:57:00.184 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 85.0 to 35.0
2024-01-26 17:18:04.848 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' changed from 5.0 to 45
2024-01-26 17:36:23.601 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35.0 to 85

It seemed to stick until I turned on the lights, and it confirmed the old value was still programmed.

What would be the best way forward to run the Zwave debug? I turned on debugging on the binding once, but thats too much data to make sense of.

Again it seems that sending the command by hand ensures it sticks. Could it be related to the burst of updates the rule sends all at once? :thinking:

2024-01-26 17:43:54.559 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 35.0
2024-01-26 17:43:54.560 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 35.0
2024-01-26 17:43:54.560 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 85 to 35.0
2024-01-26 17:46:27.964 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Dimmer' received command ON
2024-01-26 17:46:27.965 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_Dimmer' predicted to become ON
2024-01-26 17:46:27.967 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 0 to 100
2024-01-26 17:46:28.493 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Power' changed from 0 W to 0.4 W
2024-01-26 17:46:28.559 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 100 to 35

It is a lot of data, but it tells what is going on with the binding. There is a log viewer here that presents the results in more readable fashion. With the latest OH you can turn on debug from the far right column on the UI setting page. Set to debug, run rule, wait a ten seconds, then set back to info. I think whatever is going wrong is happening quickly (or not). Log should not be too long. Analyze or post.

Well that was a bit of a anti-climax. First time I ran it, I had the logs confirming that my rule ran;

# openhab.log
2024-01-26 20:59:35.839 [INFO ] [g.rule.force_initial_brightness.rb:2] - Found 8 dimmers with Initial Brighness settings
2024-01-26 20:59:35.840 [INFO ] [g.rule.force_initial_brightness.rb:2] - Updating ToiletLight_ForceInitialBrightness to Night time value
2024-01-26 20:59:35.843 [INFO ] [g.rule.force_initial_brightness.rb:2] - Updating HallwayLight_ForceInitialBrightness to Night time value
2024-01-26 20:59:35.846 [INFO ] [g.rule.force_initial_brightness.rb:2] - Updating BathroomCeilingLight_ForceInitialBrightness to Night time value

# events.log
2024-01-26 20:59:35.841 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'ToiletLight_ForceInitialBrightness' received command 20.0
2024-01-26 20:59:35.841 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'ToiletLight_ForceInitialBrightness' predicted to become 20.0
2024-01-26 20:59:35.842 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'ToiletLight_ForceInitialBrightness' changed from 65 to 20.0
2024-01-26 20:59:35.844 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 10.0
2024-01-26 20:59:35.845 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 10.0
2024-01-26 20:59:35.845 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 10.0
2024-01-26 20:59:35.847 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'BathroomCeilingLight_ForceInitialBrightness' received command 15.0
2024-01-26 20:59:35.847 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'BathroomCeilingLight_ForceInitialBrightness' predicted to become 15.0
2024-01-26 20:59:35.848 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'BathroomCeilingLight_ForceInitialBrightness' changed from 99 to 15.0 

… But absolutely nothing on the z-wave front. Waited 10 more seconds, and saw some updates from my z-wave multisensor, but nada on param19 or the dimmers at all.

So, take 2:

# openhab.log
2024-01-26 21:03:46.493 [INFO ] [g.rule.force_initial_brightness.rb:2] - Found 8 dimmers with Initial Brighness settings
2024-01-26 21:03:46.494 [INFO ] [g.rule.force_initial_brightness.rb:2] - Updating OfficeCeilingLight_ForceInitialBrightness to Evening time value
2024-01-26 21:03:46.497 [INFO ] [g.rule.force_initial_brightness.rb:2] - Updating HallwayLight_ForceInitialBrightness to Evening time value

# evens.log
2024-01-26 21:03:46.495 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'OfficeCeilingLight_ForceInitialBrightness' received command 5.0
2024-01-26 21:03:46.497 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'OfficeCeilingLight_ForceInitialBrightness' predicted to become 5.0
2024-01-26 21:03:46.497 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' changed from 45 to 5.0
2024-01-26 21:03:46.498 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 35.0
2024-01-26 21:03:46.499 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 35.0
2024-01-26 21:03:46.499 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 10.0 to 35.0
2024-01-26 21:08:31.378 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'OfficeCeilingLight_ForceInitialBrightness' changed from 5.0 to 45

openhab.log (775.0 KB) (including z-wave TRACE logs)

If I read the log right, there is only a single param19 update, to node11, which would be the balcony dimmer :confounded:

Actually using the viewer I see no changes (Set Commands) to parameter 19. It looks to me like Node 11 parameter 19 is 35, (7,45) (2,35). When those nodes are turned onthey go to those levels. Example

What this shows to me is the dimmer is turned on to the last level 35. Then after 1.5 seconds the device polls all the linked channels starting with param 19, then the switch (and later the power-but I cut that off)

What exactly does the rule look like?

EDIT: Here is a simple rule I use to set a watt reporting frequency parameter. The item is linked to the parameter channel (I still use DSL, so format might be different).

rule "Restore watt reports for prime hours"
when
    Time cron "0 0 7 ? * * *"
then
    MaytagWasher11_ReportInterval.sendCommand(900)
end

Ah, looks like I misunderstood the log output then. But it is strange not to see any SET commands for the param19, even though the commands are given.

Nothing to special:

rule 'Initial Brightness' do
  description 'Sets initial brightness levels depending on the Time of Day'

  changed vTimeOfDay

  run do |event|
    dimmers = items
      .equipments(Semantics::Lightbulb)
      .members
      .select { |item| item.name.end_with? '_ForceInitialBrightness' }

    logger.info("Found #{dimmers.count} dimmers with Initial Brighness settings")

    dimmers.each do |dimmer|
      setting = dimmer.name.sub("_ForceInitialBrightness", "_Brightness_#{event.state}")

      if items.include? setting
        logger.info("Updating #{dimmer.name} to #{event.state} time value")

        dimmer.command(items[setting].state.clamp(1, 99))
      end
    end
  end
end

The dimmers, each have a set of items; The _ForceInitialBrightness linked to the config_decimal_param19 channel, and a set of _Brightness_{Day,Evening,Night} dimmer items to store the preset values.

In the example of the Hallway Light, those contain the following values:

openhab> openhab:status  HallwayLight_Brightness_Day
85.0
openhab> openhab:status  HallwayLight_Brightness_Evening
35.0
openhab> openhab:status  HallwayLight_Brightness_Night
10.0

As the preset dimmer items can go all the way up to 100, however the param19 only accepts values up to 99, that is why I use the clamp() function.

As we are seeing the ItemCommandEvent, I wasn’t suspicious of the rule, which also worked for more then a year :slight_smile:

The rule is too much for me, sorry (you saw mine :wink:) The only question I have is how does

compare to
item.sendCommand()

Question for @rlkoshak

EDIT: All that says is the rule progressed to that point, not that anything actually happened

I’m guessing the rule is written in jRuby, in which case the syntax looks reasonable. But I’m no expert.

dimmer is a variable created and populated by iterating over filtered members of a Group so I would expect it to be an Item Object which should have sendCommand().

1 Like

I have quite a few JRuby rules, and am confident the .command() is correct (:heart: JRuby)
We are also seeing the openhab.event.ItemCommandEvent event in the logs when the rule runs, instead of a error for the rule.

If we assume the rule does indeed send some command to the param19 item, what could cause this command to not be processed by the binding?

Could this be something related to the quantity type changes?
The HallwayLight_Brightness_{Day,Evening,Night} are Dimmer items, whereas HallwayLight_ForceInitialBrightness is a Number. These used to be compatible, and reason for the Dimmer items is, so they can easily be adjusted with a slider.

Random idea: spurred by the quantity type comment. Change presets to not include decimal point. (ie 85, not 85.0)

Ok, here we go;

openhab> openhab:status HallwayLight_ForceInitialBrightness
35
openhab> openhab:status HallwayLight_Brightness_Day
85.0
openhab> openhab:send HallwayLight_Brightness_Day 85
Command has been sent successfully.

Log confirms

[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Brightness_Day' received command 85

Let’s switch the TimeOfDay

openhab> openhab:send vTimeOfDay 'Day'
Command has been sent successfully.

[INFO ] [g.rule.force_initial_brightness.rb:2] - Updating HallwayLight_ForceInitialBrightness to Day time value

[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'vTimeOfDay' received command Day
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'vTimeOfDay' changed from Afternoon to Day
[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 85
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 85
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 85

And test

openhab> openhab:send HallwayLight_Dimmer ON
Command has been sent successfully.
openhab> openhab:send HallwayLight_Dimmer OFF
Command has been sent successfully.

[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Dimmer' received command ON
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_Dimmer' predicted to become ON
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 0 to 100
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 100 to 35
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Power' changed from 0 W to 0.5 W
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 85 to 35
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Power' changed from 0.5 W to 8.6 W
[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Dimmer' received command OFF
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_Dimmer' predicted to become OFF
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 35 to 0

Bummer… Checking one more time if the manual set still works.

openhab> openhab:send HallwayLight_ForceInitialBrightness 85
Command has been sent successfully.
openhab> openhab:send HallwayLight_Dimmer ON
Command has been sent successfully.
openhab> openhab:send HallwayLight_Dimmer OFF
Command has been sent successfully.

[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 85
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 85
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 85
[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Dimmer' received command ON
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_Dimmer' predicted to become ON
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 0 to 100
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Power' changed from 0 W to 0.4 W
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 100 to 85
[INFO ] [openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_Dimmer' received command OFF
[INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_Dimmer' predicted to become OFF
[INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_Dimmer' changed from 85 to 0

But, I think we might be on to something, let me tear the rule apart and test it bit by bit.

… one moment please

… here we go.

I took the core of the script and created a little test routing, that looks like this:


dimmer = HallwayLight_ForceInitialBrightness

logger.info("Dimmer #{dimmer.name.split('_').first} is at #{dimmer.state}")

settings_item  = dimmer.name.sub("_ForceInitialBrightness", "_Brightness_Day")
settings_value = items[settings_item].state.clamp(1, 99)

logger.info("New brightness setting is: #{settings_value}")

dimmer.command(settings_value)

sleep 5

HallwayLight_Dimmer.on

sleep 2

HallwayLight_Dimmer.off

sleep 2

logger.info("Brightness is now at: #{dimmer.state}")

Which returns the following results:

[INFO ] [ion.jrubyscripting.script.scratchpad] - Dimmer HallwayLight is at 35
[INFO ] [ion.jrubyscripting.script.scratchpad] - New brightness setting is: 85%
[INFO ] [ion.jrubyscripting.script.scratchpad] - Brightness is now at: 35

It seems that the ‘Dimmer’ item that stores the preset value for the day, stores it as a percentage value. Whereas the param19 item seems to use a plain ‘Number’.

If cast the value to a integer (inserting a to_i before the clamp()), it actually works.

I tried to verify/replicate this using the CLI, but when sending 85% as a value, it works. The logs are slightly different, the command clearly shows the percentage in the command. Which, when the percentage is set from the rule, is not.

openhab> openhab:send HallwayLight_ForceInitialBrightness '85%'
Command has been sent successfully.

[openhab.event.ItemCommandEvent      ] - Item 'HallwayLight_ForceInitialBrightness' received command 85 %
[penhab.event.ItemStatePredictedEvent] - Item 'HallwayLight_ForceInitialBrightness' predicted to become 85 %
[openhab.event.ItemStateChangedEvent ] - Item 'HallwayLight_ForceInitialBrightness' changed from 35 to 85

One thing I tried is to specifically cast the value send by the command to a percentage (dimmer.command(settings_value | '%'), this generates the same logs and working result as the manual cli tests.

I’ve also removed the clmap() to see if that creates the issues, but it does not seem to matter.

So it seems sending the state of a ‘Dimmer’, which is a percentage, to a item that controls param19, results in something that the binding does not like.

FYI

  1. I think this is related to when the rule stopped working. OH 3 to OH 4 : most percentage values are now divided by 100 - Setup, Configuration and Use / Migration - openHAB Community
  2. AFAIK Zwave parameters are always integers. For that matter Zwave reports also are always integers, but there is an “explanation” byte that defines “precision” or where to put the decimal. Based on your work and my understanding raw dimmer is from 0 - 99 (100) and now with 4.0 the OH core changes that.