[BLOCKY] reschedule block triggers only once

[enrico-cc]

The problem

when using the "reschedule" block in a rule (script), the first time the rule is triggered the timer is properly rescheduled, but the second time it’s not.

Expected behavior

every time that the rule is triggered, it should reschedule the timer

Steps to reproduce

Example:

I created a rule to turn on a light when motion is detected and turn off when no motion detected for 3 minutes.
The rule is triggered by the motion sensor changing to ON:

the behavior I experience is the following:
If I stay in the room for less than 5 minutes (I tested 4.5 minutes) and the I exit, the light turns off.
If I stay in the room for more than 5 minutes and then exit, the light never turns off.
Consider also that the motion sensor has a 60 seconds “cooldown” after being triggered, and if motion is detected when it’s already ON, there is no change in the item state.

Logs:
2021-11-25 18:53:12.398 [INFO ] [org.openhab.rule.b7323e80df ] - timer start
2021-11-25 18:56:12.413 [INFO ] [org.openhab.rule.b7323e80df ] - Timer finished
2021-11-25 18:56:12.527 [INFO ] [org.openhab.rule.b7323e80df ] - Else if condition met > reschedule
2021-11-25 18:59:12.502 [INFO ] [org.openhab.rule.b7323e80df ] - Timer finished
2021-11-25 18:59:12.551 [INFO ] [org.openhab.rule.b7323e80df ] - Else if condition met > reschedule

Your environment

runtimeInfo:
version: 3.2.0.M4
buildString: Milestone Build
locale: en-IT
systemInfo:
configFolder: /etc/openhab
userdataFolder: /var/lib/openhab
logFolder: /var/log/openhab
javaVersion: 11.0.13
javaVendor: Azul Systems, Inc.
javaVendorVersion: Zulu11.52+13-CA
osName: Linux
osVersion: 5.10.63-v7+
osArchitecture: arm
availableProcessors: 4
freeMemory: 73255232
totalMemory: 195035136
bindings:

• airquality
• astro
• avmfritz
• chromecast
• mail
• mihome
• miio
• mqtt
• network
• openweathermap
• openwebnet
• sonoff
  clientInfo:
  device:
  ios: false
  android: false
  androidChrome: false
  desktop: true
  iphone: false
  ipod: false
  ipad: false
  edge: false
  ie: false
  firefox: false
  macos: false
  windows: true
  cordova: false
  phonegap: false
  electron: false
  nwjs: false
  webView: false
  webview: false
  standalone: false
  os: windows
  pixelRatio: 1.25
  prefersColorScheme: light
  isSecureContext: false
  locationbarVisible: true
  menubarVisible: true
  navigator:
  cookieEnabled: true
  deviceMemory: N/A
  hardwareConcurrency: 8
  language: en-US
  languages:
  • en-US
  • it-IT
  • it
  • en
    onLine: true
    platform: Win32
    screen:
    width: 1536
    height: 864
    colorDepth: 24
    support:
    touch: false
    pointerEvents: true
    observer: true
    passiveListener: true
    gestures: false
    intersectionObserver: true
    themeOptions:
    dark: light
    filled: true
    pageTransitionAnimation: default
    bars: filled
    homeNavbar: default
    homeBackground: default
    expandableCardAnimation: default
    userAgent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML,
    like Gecko) Chrome/96.0.4664.27 Safari/537.36
    timestamp: 2021-11-28T08:54:36.070Z

Browser console

N/A

Browser network traffic

N/A

Additional information

Openhab thread:
https://community.openhab.org/t/script-with-blocky-reschedule-block-triggers-only-once/129190/4

[ghys]

In general when reporting Blockly issues you should paste the code that's been generated (with Ctrl-B or the blue button at the bottom-right.

In this case though I think I can see the problem.
Here:

openhab-webui/bundles/org.openhab.ui/web/src/assets/definitions/blockly/blocks-timers.js

Line 83 in 1e916da

code += ` this.timers[${timerName}] = undefined;\n`

The timer is set to undefined after it has run, no matter what.

The reschedule block checks that the timer exists before calling .reschedule().

openhab-webui/bundles/org.openhab.ui/web/src/assets/definitions/blockly/blocks-timers.js

Line 324 in 1e916da

let code = `if (typeof this.timers[${timerName}] !== 'undefined') { this.timers[${timerName}].reschedule(zonedDateTime.now().${delayUnits}(${delay})); }\n`

On the first run of the timer, it will still exist because the code to execute is inserted before this this.timers[${timerName}] = undefined;. If you reschedule the timer within its own code, though, since it will be always unset after the first run, on the second run it will be gone - and no second rescheduling happens.

So this unsetting should only happen if the timer has not been rescheduled - maybe by checking .isActive()?

https://github.com/openhab/openhab-core/blob/a4b737c40162a01bd8c5b35a5d15b2f83680079c/bundles/org.openhab.core.model.script/src/org/openhab/core/model/script/actions/Timer.java#L40-L45

cc @stefan-hoehn

[enrico-cc]

Hi Yannick,

thanks for checking.

The fact that the timer is set to undefined after it has run, no matter what, isn't a bug in the block?
If the timer is rescheduled before the timer it's expired, IMHO the timer shouldn't be set to undefined.

this is the code:

var logger = Java.type('org.slf4j.LoggerFactory').getLogger('org.openhab.rule.' + ctx.ruleUID);

var scriptExecution = Java.type('org.openhab.core.model.script.actions.ScriptExecution');

var zonedDateTime = Java.type('java.time.ZonedDateTime');

if (typeof this.timers === 'undefined') {
  this.timers =[];
}


if (itemRegistry.getItem('LuceBagnoPiano6').getState() == 'OFF' && itemRegistry.getItem('MovimentoBagnoP6_Illumination').getState() <= '30') {
  events.sendCommand('LuceBagnoPiano6', 'ON');
}
logger.info('timer start');
if (typeof this.timers['TimerLuceBagnoP6'] === 'undefined') {
  this.timers['TimerLuceBagnoP6'] = scriptExecution.createTimer(zonedDateTime.now().plusSeconds(180), function () {
    logger.info('Timer finished');
    if (itemRegistry.getItem('LuceBagnoPiano6').getState() == 'ON' && itemRegistry.getItem('MovimentoBagnoP6_MotionStatus').getState() == 'OFF') {
      events.sendCommand('LuceBagnoPiano6', 'OFF');
    } else if (itemRegistry.getItem('LuceBagnoPiano6').getState() == 'ON' && itemRegistry.getItem('MovimentoBagnoP6_MotionStatus').getState() == 'ON') {
      if (typeof this.timers['TimerLuceBagnoP6'] !== 'undefined') { this.timers['TimerLuceBagnoP6'].reschedule(zonedDateTime.now().plusSeconds(180)); }
      logger.info('Else if condition met > reschedule');
    }
    this.timers['TimerLuceBagnoP6'] = undefined;
  })
} else {
  this.timers['TimerLuceBagnoP6'].reschedule(zonedDateTime.now().plusSeconds(180));
}
logger.info('end of script');

[ghys]

Yes it's a bug in the block.

If the timer is rescheduled before the timer it's expired, IMHO the timer shouldn't be set to undefined.

That's what I meant by

So this unsetting should only happen if the timer has not been rescheduled - maybe by checking .isActive()?

[enrico-cc]

my bad, I thought you were suggesting me to manually change the script 👍

[ghys]

Fortunately it looks like the "is active" check would work... So it would be an easy fix.

Results in:

---
Timer running
Timer is active
Timer has not terminated
Timer is running
---
Timer running
Timer is not active
Timer has not terminated
Timer is not running

Interestingly, the timer is not reported as running the second time, probably a race condition.

[stefan-hoehn]

@enrico-cc It seems Yannick has understood the problem right away and knows how to fix it but I don't yet understand the problem fully. Can you please strip down your example to the bare minimum that I would be able to run and reproduce? So please provide the most simple version that shows the problem together with what you expect and what is happening. As soon as I have understood that I will work on fix quickly and release a bugfix soon.

btw, @ghys it seems I wasn't notified by github, so I only by chance have seen the issue. I need to check the gh notification.

[enrico-cc]

Hi Stefan,

this is the fastest test I can think of:

This should create an infinite loop, instead it's executed only twice.

the cause of this behavior has been identified by Yannic:

"The timer is set to undefined after it has run, no matter what.
The reschedule block checks that the timer exists before calling .reschedule().

On the first run of the timer, it will still exist because the code to execute is inserted before this this.timers[${timerName}] = undefined;. If you reschedule the timer within its own code, though, since it will be always unset after the first run, on the second run it will be gone - and no second rescheduling happens."

[stefan-hoehn]

@enrico-cc see the comment here