New Automation: Pulse Width Modulation (PWM)

[fwolter (Fabian Wolter)]

I made a JAR logging also the rule UID:

20:12:23.048 [TRACE] [ion.pwm.internal.handler.state.State] - 5a0e3d36a0: OnState -> OffState

https://github.com/fwolter/openhab-addons/releases/download/fix-pwm/org.openhab.automation.pwm-3.4.0-SNAPSHOT.jar

[Jacek_Kaczmarczyk (Jacek Ka)]

Hi, @fwolter … still having some issue with pwm sending command to relay every interval. i have 2 hosts with the same rules/items:

1/ Working as expected:
Relay Item is receiving ON OFF command every loop.

2022-12-15 23:04:33.452 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:14:33.463 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_Relay' received command OFF
2022-12-15 23:14:33.465 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'RadiatorAC3_PWM_Relay' predicted to become OFF
2022-12-15 23:16:00.649 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_scheduled_TargetTemperature' received command 19.0
2022-12-15 23:16:00.651 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_TargetTemperature' received command 19.0
2022-12-15 23:19:33.449 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:19:33.455 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -4.5549952000000005 to -5.630196394666667
2022-12-15 23:29:33.472 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_Relay' received command OFF
2022-12-15 23:29:33.474 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'RadiatorAC3_PWM_Relay' predicted to become OFF
2022-12-15 23:31:00.650 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_scheduled_TargetTemperature' received command 19.0
2022-12-15 23:31:00.652 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_TargetTemperature' received command 19.0
2022-12-15 23:34:33.453 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -5.630196394666667 to -6.705398784000001
2022-12-15 23:34:33.457 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:44:33.473 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_Relay' received command OFF
2022-12-15 23:44:33.475 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'RadiatorAC3_PWM_Relay' predicted to become OFF
2022-12-15 23:46:00.648 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_scheduled_TargetTemperature' received command 19.0
2022-12-15 23:46:00.652 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_TargetTemperature' received command 19.0

2/ Different host:

2022-12-15 23:36:26.003 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -97.6788891166669 to -97.8048891166669
2022-12-15 23:36:26.005 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PWM_dutycycleItem' updated to 0
2022-12-15 23:38:25.994 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_pInspector' updated to -58.49999999999991
2022-12-15 23:38:25.996 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_iInspector' updated to -97.9308901666669
2022-12-15 23:38:25.998 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_eInspector' updated to -0.8999999999999986
2022-12-15 23:38:26.000 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:38:26.001 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -97.8048891166669 to -97.9308901666669
2022-12-15 23:38:26.002 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PWM_dutycycleItem' updated to 0
2022-12-15 23:40:25.994 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_pInspector' updated to -58.49999999999991
2022-12-15 23:40:25.997 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_iInspector' updated to -98.0568912166669
2022-12-15 23:40:25.999 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_eInspector' updated to -0.8999999999999986
2022-12-15 23:40:26.001 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:40:26.003 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -97.9308901666669 to -98.0568912166669
2022-12-15 23:40:26.004 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PWM_dutycycleItem' updated to 0
2022-12-15 23:42:25.995 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_pInspector' updated to -58.49999999999991
2022-12-15 23:42:26.000 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_iInspector' updated to -98.18289121666689
2022-12-15 23:42:26.004 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_eInspector' updated to -0.8999999999999986
2022-12-15 23:42:26.007 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'RadiatorAC3_PWM_dutycycleItem' received command 0
2022-12-15 23:42:26.063 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'RadiatorAC3_PID_iInspector' changed from -98.0568912166669 to -98.18289121666689
2022-12-15 23:42:26.065 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PWM_dutycycleItem' updated to 0
2022-12-15 23:44:25.997 [INFO ] [openhab.event.ItemStateEvent        ] - Item 'RadiatorAC3_PID_pInspector' updated to -58.49999999999991

PID controller is working but PWM is not sending command to an item. Interval settings:
working host : PWM interval: 1800.0
bad host: PWM interval: 900 - so it should send the command even more frequently

[Jacek_Kaczmarczyk (Jacek Ka)]

@fwolter

org.openhab.automation.pwm

Did some investigation… i have 17 PWM rules running at the same time, with the same config, created in js loop. Look what is interesting in tracing it with your JAR with logging.

2022-12-16 00:23:38.666 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 0.0
2022-12-16 00:23:38.967 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 0.0
2022-12-16 00:23:39.635 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 0.0
2022-12-16 00:23:39.667 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 0.0
2022-12-16 00:23:39.899 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 0.0
2022-12-16 00:23:40.177 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Received new duty cycle: 78.0
2022-12-16 00:23:40.390 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_8_PWM_rule: Received new duty cycle: 90.0
2022-12-16 00:23:41.044 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_9_PWM_rule: Received new duty cycle: 100.0
2022-12-16 00:23:41.892 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_11_PWM_rule: Received new duty cycle: 100.0
2022-12-16 00:23:42.352 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_12_PWM_rule: Received new duty cycle: 0.0
2022-12-16 00:23:43.108 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_13_PWM_rule: Received new duty cycle: 87.0
2022-12-16 00:23:43.318 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_14_PWM_rule: Received new duty cycle: 0.0
2022-12-16 00:23:43.546 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_15_PWM_rule: Received new duty cycle: 100.0
2022-12-16 00:23:43.804 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_16_PWM_rule: Received new duty cycle: 0.0
2022-12-16 00:23:44.059 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_17_PWM_rule: Received new duty cycle: 100.0
2022-12-16 00:24:57.248 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_14_PWM_rule: Received new duty cycle: 0.0

Rules with id 1-9 are not translated into rule “name” like others 10-17* - 10 is not visible at this part of the log but it is there.

if i disable and re-enable te rule, the name of the rule is visible, but there is an error showing

2022-12-16 11:54:28.251 [DEBUG] [m.internal.handler.PWMTriggerHandler] - Termostat_1_PWM_rule: Received new duty cycle: 0.0
2022-12-16 11:54:28.255 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching/filtering event for subscriber 'org.openhab.core.events.EventSubscriber' failed: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@7c9c689c[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@7c4d246f[Wrapped task = org.openhab.automation.pwm.internal.handler.PWMTriggerHandler$$Lambda$1913/0x00000001016fc440@4f2f3155]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@76f95b33[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@7c9c689c[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@7c4d246f[Wrapped task = org.openhab.automation.pwm.internal.handler.PWMTriggerHandler$$Lambda$1913/0x00000001016fc440@4f2f3155]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@76f95b33[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
        at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2055) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:825) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340) ~[?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562) ~[?:?]
        at java.util.concurrent.Executors$DelegatedScheduledExecutorService.schedule(Executors.java:779) ~[?:?]
        at org.openhab.automation.pwm.internal.handler.PWMTriggerHandler.lambda$4(PWMTriggerHandler.java:186) ~[?:?]
        at java.util.Optional.ifPresent(Optional.java:183) ~[?:?]
        at org.openhab.automation.pwm.internal.handler.PWMTriggerHandler.restartDeadManSwitchTimer(PWMTriggerHandler.java:185) ~[?:?]
        at org.openhab.automation.pwm.internal.handler.PWMTriggerHandler.receive(PWMTriggerHandler.java:137) ~[?:?]
        at org.openhab.core.internal.events.EventHandler.lambda$0(EventHandler.java:151) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:829) [?:?]

is this jar conteing the “PWM disable fix” ? regardles of this error pwm module seems to work

[fwolter (Fabian Wolter)]

@Jacek_Kaczmarczyk

to early to say but have some feedback / questions
1/ When the PWM rule parameters are being reloaded in my setup i am creating rules from jss scripts and parameters are taken from item.states. Does DISABLING AND ENABLING the rule refresh the parameters from items e.a. Interval or i need to reload the rule.js file
2/ it will be good to add some startup logging in DEBUG like : PWM module started with : interval : 10s, setting1 : x, setting2: y it will show the current settings and ensure me that the module is reloaded.
3/ and maybe also log the action send to relay item (TRACE)

I can’t help you with the the JavaScript rules.
What’s the use cases modifying the configuration parameters during runtime?
You see updates of Items when enabling logging of openhab.event.

The disable error is fixed with the next OH version, released in a few days.