How do I debug or log timer functionality

  • Platform information:
    • Hardware: x86_64
    • OS: Ubuntu 23.10 (mantic), 6.5.0-27-generic
    • Java Runtime Environment: OpenJDK 64-Bit Server VM Zulu17.50+19-CA (build 17.0.11+9-LTS, mixed mode, sharing)
    • openHAB version: 4.2.0.M2 (Build)
  • Issue of the topic: Timers created through blockly rules do not seem to fire. I am attempting to set a 15 minute timer to shut off lights in an area after the last detected motion or switch from two different motion sensors and two different switches.
  • Please post configurations (if applicable): Generated code from blockly
    • Items configuration related to the issue: N/A
    • Sitemap configuration related to the issue: N/A
    • Rules code related to the issue
if (cache.private.exists('GarageSaver') === false || cache.private.get('GarageSaver').hasTerminated()) {
  cache.private.put('GarageSaver', actions.ScriptExecution.createTimer('GarageSaver', time.ZonedDateTime.now().plusMinutes(15), function () {
    items.getItem('Garage_Light').sendCommand('OFF');
    items.getItem('Shop_Light').sendCommand('OFF');
    }));
} else {
  cache.private.get('GarageSaver').reschedule(time.ZonedDateTime.now().plusMinutes(15));
};
  • Services configuration related to the issue: N/A
  • If logs where generated please post these here using code fences:
    I can not find any logs related to timers. I see rule triggers fire but nothing after the original trigger to suggest that the timer is trying and failing or whatever. I faced this same problem in previous versions of OpenHAB and instead pivoted to doing a persistence query. I would like to move to the simpler rule but could use some help working out how to troubleshoot timers.

Show the whole rule. Click on the “code” tab so we can see the rule triggers in context.

I suspect that what ever is triggering the rule is doing so more often than every 15 minutes causing the timer to perpetually be rescheduled.

Adding a simple log block as the first block of the script will confirm if that’s the case.

Thanks, I added some log elements right after I sent this. With the logs, I could see that my trigger was never hitting. I had it triggered on the two switches to get the command of ON. Perhaps because of my setup with zwave-js-ui, that command is never coming through. I just changed it to trigger when the motion sensor updates to true. Here is my current version of the rule.

configuration: {}
triggers:
  - id: "1"
    configuration:
      itemName: Garage_Sensor_Motion
      state: "true"
    type: core.ItemStateUpdateTrigger
  - id: "2"
    configuration:
      itemName: Shop_Sensor_Motion
      state: "true"
    type: core.ItemStateUpdateTrigger
conditions: []
actions:
  - inputs: {}
    id: "3"
    configuration:
      blockSource: <xml xmlns="https://developers.google.com/blockly/xml"><block
        type="oh_log" id=",kEwQPyP]G#9Qmc+K6K_" x="156" y="74"><field
        name="severity">info</field><value name="message"><shadow type="text"
        id="UYU/RLsj`oottSZD6PAT"><field name="TEXT">abc</field></shadow><block
        type="text" id="G5;_8k4$Xh0#?l!m.Pm?"><field name="TEXT">Starting or
        triggering reset timer for
        GarageSaver</field></block></value><next><block type="oh_timer_ext"
        id="xbMHn0-xa$vg]+e1io8#"><field
        name="delayUnits">plusMinutes</field><field
        name="cache">private</field><field
        name="retrigger">reschedule</field><value name="delay"><shadow
        type="math_number" id="KJYa~?eNX~N[y6]nugl("><field
        name="NUM">10</field></shadow><block type="math_number"
        id="LV`H]2mXdf=@x/@%t}.Q"><field
        name="NUM">15</field></block></value><value name="timerName"><shadow
        type="text" id="}WQkIaJ%zU`*V*-vrdTA"><field
        name="TEXT">MyTimer</field></shadow><block type="text"
        id="d$:3uW5y;5!([oE{tzh`"><field
        name="TEXT">GarageSaver</field></block></value><statement
        name="timerCode"><block type="oh_log" id="es]-l}xnz;;Jf~2$HXTn"><field
        name="severity">info</field><value name="message"><shadow type="text"
        id="N3!tf1nUC_Ct5[ddvXe7"><field name="TEXT">abc</field></shadow><block
        type="text" id="ym_A(`L-;%@NBIH*?O02"><field name="TEXT">Executing from
        GarageSaver timer</field></block></value><next><block type="oh_event"
        id="n.v8`Lq|M[F;T$xTfANy"><field
        name="eventType">sendCommand</field><value name="value"><shadow
        type="text" id="^_CKNxf)]*w+Y[?PZ=S!"><field
        name="TEXT">value</field></shadow><block type="text"
        id="JrOh^AYw3^fu^_[`MEJ4"><field
        name="TEXT">OFF</field></block></value><value name="itemName"><shadow
        type="oh_item" id="K7WL//#W_ca4kN?kI#ed"><mutation itemName="MyItem"
        itemLabel="MyItem"></mutation><field
        name="itemName">MyItem</field></shadow><block type="oh_item"
        id="%P^F,5I2nC-aA}=Es;b/"><mutation itemName="Garage_Light"
        itemLabel="Garage Light"></mutation><field
        name="itemName">Garage_Light</field></block></value><next><block
        type="oh_event" id="y:x8-ti3o`aTY(ots8e}"><field
        name="eventType">sendCommand</field><value name="value"><shadow
        type="text" id="^_CKNxf)]*w+Y[?PZ=S!"><field
        name="TEXT">value</field></shadow><block type="text"
        id="0GZgJ(q0MF0O!(ZVh{}~"><field
        name="TEXT">OFF</field></block></value><value name="itemName"><shadow
        type="oh_item" id="K7WL//#W_ca4kN?kI#ed"><mutation itemName="MyItem"
        itemLabel="MyItem"></mutation><field
        name="itemName">MyItem</field></shadow><block type="oh_item"
        id="?DS%SY)s}#r:mu2/n|+z"><mutation itemName="Shop_Light"
        itemLabel="Shop Light"></mutation><field
        name="itemName">Shop_Light</field></block></value></block></next></block></next></block></statement></block></next></block></xml>
      type: application/javascript
      script: >
        console.info('Starting or triggering reset timer for GarageSaver');

        if (cache.private.exists('GarageSaver') === false ||
        cache.private.get('GarageSaver').hasTerminated()) {
          cache.private.put('GarageSaver', actions.ScriptExecution.createTimer('GarageSaver', time.ZonedDateTime.now().plusMinutes(15), function () {
            console.info('Executing from GarageSaver timer');
            items.getItem('Garage_Light').sendCommand('OFF');
            items.getItem('Shop_Light').sendCommand('OFF');
            }));
        } else {
          cache.private.get('GarageSaver').reschedule(time.ZonedDateTime.now().plusMinutes(15));
        };
    type: script.ScriptAction

Well, that worked. I was expecting to be able to update a log4j setting to see timer things or hit the embedded database or something. Simply adding log statements in my blockly scripts did the trick.