Threshold Alert and Open Reminder [4.0.0.0;5.9.9.9]

Larsen · November 3, 2024, 5:45pm

Nothing, that should work. Even if you spell it wrong you should see the logger with log:list.
Is openhab running?

ErikDB · November 3, 2024, 7:14pm

It was.

rlkoshak · November 3, 2024, 8:06pm

You can set the level of the org.openhab.automation.rules_tools.Threshold Alert.<ruleUID> logger in all the usual ways (karaf console, REST API) to DEBUG or, at the top of the script action of the rule there is a commented out line of code that sets the level. You can uncomment it and run the rule once and then comment it back out.

//osgi.getService('org.apache.karaf.log.core.LogService').setLevel(console.loggerName, 'DEBUG');

You don’t have the right logger name. See above or see the top few lines of the script action in the TA rule.

Unless yoiu changed it, the rule gets triggered by changes to members of the Group. The rule doesn’t use nor does it care anything about changes to the Group itself.

You need to post your config up to and including your Items. This rule only gets triggered my members of a single Group. How do you have this rule being triggered since you seem to have multiple Groups?

No, every change to any direct member of the triggering group will trigger the rule. But if you have Groups of Groups only changes to the subgroups will trigger the rule. Changes to their members will only trigger the rule if those changes cause the state of the Group to change. Given the way aggregation functions work, that is not guaranteed to happen.

Triggering this rule with a Group of Groups is not directly supported.

ErikDB · November 3, 2024, 8:55pm

Group item haarden_procesbeschermingstimers has two members: haard_salon_procesbeschermingstimer and haard_eetkamer_procesbeschermingstimer:

Group:Number:Time haarden_procesbeschermingstimers "Haarden - Procesbeschermingstimers" <time>
Number:Time haard_salon_procesbeschermingstimer "Haard salon - Procesbeschermingstimer" <time> (haard_salon_groep, haarden_procesbeschermingstimers)
Number:Time haard_eetkamer_procesbeschermingstimer "Haard eetkamer - Procesbeschermingstimer" <time> (haard_eetkamer_groep, haarden_procesbeschermingstimers)

So no groups within groups…

rlkoshak · November 4, 2024, 2:41am

OK, then assuming that haarden_procesbeschermingstimers is the trigger for the rule, the rule will trigger every time any member of that Group changes. OH does not lose change events.

The logs related to changes to the state of haarden_procesbeschermingstimers itself are irrelevant to the operation of the rule. The rule ignores those events.

Note, if you are not using the state of this Group for anything, you may as well just define it as a plain old Group without a type.

ErikDB · November 4, 2024, 4:19pm

That all makes sense…

But something went wrong… I’ll try to debug log once I get an opportunity.

ErikDB · November 4, 2024, 8:07pm

I did that, but:

21:05:27.151 [ERROR] [.internal.handler.ScriptActionHandler] - Script execution of rule with UID 'haarden-procesbescherming-UIT' failed: java.lang.RuntimeException: Unable to set level for logger

rlkoshak · November 4, 2024, 9:01pm

That error is rather non-specific. I’ve never seen that before.

I just tested it a couple of times on my rules and it worked as expected. Maybe there was a trick of timing? Have you tried more than once?

ErikDB · November 4, 2024, 9:22pm

I tried it 5 more times, always with the same result…

For the full picture, this is my alteration to the script (one never knows whether that has any influence):

// Version 1.2
var {helpers, LoopingTimer, Gatekeeper, timeUtils, RateLimit} = require('openhab_rules_tools');
var {DecimalType, QuantityType, PercentType} = require('@runtime');

var loggerBase = 'org.openhab.automation.rules_tools.Threshold Alert.'+ruleUID;
console.loggerName = loggerBase;
osgi.getService('org.apache.karaf.log.core.LogService').setLevel(console.loggerName, 'DEBUG');

helpers.validateLibraries('4.1.0', '2.0.3');

console.debug('Starting threshold alert');

// ~~~~~~~~~~~~~~~~~~~~~~~~ Toevoegingen Erik ~~~~~~~~~~~~~~~~~~~~~~~~

var kamersenhaarden = [
  "eetkamer",
  "salon"
];

var verderzoeken = true;
for (let x = 0; x < kamersenhaarden.length && verderzoeken; x++) {
  if (String(event.itemName).toLowerCase().includes(kamersenhaarden[x])) {
    var kamernaam = kamersenhaarden[x];
    verderzoeken = false;
  }
}

var alertRuleUID = "haard_"+ kamernaam +"_procesbescherming_UIT";


// BELANGRIJK!
// BELANGRIJK!
// BELANGRIJK!- Hieronder moet alertRuleUID verwijderd worden!
// BELANGRIJK!
// BELANGRIJK!

// ~~~~~~~~~~~~~~~~~~~~~ Einde toevoegingen Erik ~~~~~~~~~~~~~~~~~~~~~


// Properties
var group = 'haarden_procesbeschermingstimers';
var thresholdStr = '0 s';
var operator = '==';
var comparison = (currState, threshold) => { return currState == threshold; };
var invert = false;
var defaultAlertDelay = 'PT2S';
var defaultRemPeriod = '';
var namespace = 'thresholdAlert';
//var alertRuleUID = 'haard_eetkamer_procesbescherming_UIT';
var endAlertUID = '';
var dndStart = '00:00';
var dndEnd = '00:00';
var gkDelay = 0;
var hystRange = '';
var rateLimitPeriod = '';
var reschedule = false;
var initAlertRuleUID = '';

// ~~~~~~~~~~~Functions
/**
 * Converts an Item's state to a value we can compare in this rule.
 *
 * @param {State|string} an Item's state
 * @return {String|float|Quantity} the state converted to a usable type
 */
var stateToValue = (state) => {
  console.debug('Processing state ' + state + ' of type ' + typeof state);
  if(typeof state === 'string') {
    console.debug('state is a string: ' + state);
    if(state.includes(' ')) {
      try {
        console.debug('state is a Quantity: ' + state);
        return Quantity(state)
      } catch(e) {
        // do nothing, leave it as a String
        console.debug('Not a Quantity but has a space, leaving as a string: ' + state);
        return state;
      }
    }
    else if(state == '') {
      console.debug('state is the empty string, no conversion possible');
      return state;
    }
    else if(!isNaN(state)) {
      console.debug('state is a number: ' + state)
      return Number.parseFloat(state);
    }
    else if(state == 'UnDefType' || state == 'NULL' || state == 'UNDEF') {
      console.debug('state is an undef type, normalizing to UnDefType');
      return 'UnDefType';
    }
    console.debug('Leaving state as a string');
    return state;
  }
  else if(state instanceof DecimalType || state instanceof PercentType) {
    console.debug('state is a DecimalType or PercentType: ' + state);
    return state.floatValue();
  }
  else if(state instanceof QuantityType) {
    console.debug('state is a QuantityType, converting to Quantity: ' + state);
    return Quantity(state);
  }
  else {
    console.debug('Not numeric, leaving as a string: ' + state);
    return state.toString();
  }
}


/**
 * Determines if the Item is in an alerting state based on the configured comparison.apply
 *
 * @param {string|float|Quantity} current state of the Item
 * @param {Object} record the Item's record of properties and timers
 * @param {function(a,b)} operator the comparison operator to use
 * @return {boolean} true if current is an alerting state
 */
var isAlertingState = (currState, record) => {
  let calc = currState + ' ' + record.operator + ' ' + record.threshold;
  if(record.invert) calc = '!(' + calc + ')';
  console.debug('Checking if we are in the alerting state: ' + calc);

  let rval = record.compare(currState, record.threshold);
  rval = (record.invert) ? !rval : rval;
  console.debug('Result is ' + rval);
  return rval;
}

/**
 * Checks the proposed alerting time and adjusts it to occur at the end of the DND
 * if the proposed time falls in the DND time.
 *
 * @param {anything supported by time.toZDT()} timeout proposed time to send the alert
 * @param {String} dndStart time the DND starts
 * @param {String} dndEnd time the DND ends
 * @return {time.ZonedDateTime} adjusted time to send the alert or null if there is a problem
 */
var generateAlertTime = (timeout, dndStart, dndEnd) => {
  if(timeout === '' || (!(timeout instanceof time.ZonedDateTime) && !validateDuration(timeout))){
    console.debug('Timeout ' + timeout + ' is not valid, using null');
    return null;
  }

  let rval = time.toZDT(timeout.toString());
  let start = time.toZDT(dndStart);
  let end = time.toZDT(dndEnd);
  if(rval.isBetweenTimes(start, end)) {
    console.debug('Alert is scheduled during do not distrub time, moving to ' + dndEnd);
    rval = end;
    if(time.toZDT(rval).isBefore(time.toZDT())) {
      console.debug('Moving alert time to tomorrow');
      rval = timeUtils.toTomorrow(end);
    }
  }
  return rval;
}

/**
 * Calls the rule with the alert info, using the gatekeeper to prevent overloading the
 * rule. The rule is called to inforce conditions.
 *
 * @param {string|float|Quantity} state Item state that is generating the alert
 * @param {string} ruleID rule to call
 * @param {boolean} isAlerting indicates if the Item is alerting or not
 * @param {boolean} isInitialAlert indicates if the Item is just detected as alerting but not yet alerted
 * @param {Object} record all the information related to the Item the rule is being called on behalf of
 */
var callRule = (state, ruleID, isAlerting, isInitialAlert, record) => {

  if(ruleID == '') {
    console.debug('No rule ID passed, ignoring');
    return;
  }

  console.debug('Calling ' + ruleID + ' with alertItem=' + record.name + ', alertState=' + state + ', isAlerting='
                + isAlerting + ', and initial alert ' + isInitialAlert);
  var rl = cache.private.get('rl', () => RateLimit());

  const throttle = () => {
    const gk = cache.private.get('gatekeeper', () => Gatekeeper());
    const records = cache.private.get('records');
    gk.addCommand(record.gatekeeper, () => {
      try {
        // If the Item hasn't triggered this rule yet and therefore doesn't have a record, skip it
        const allAlerting = items[group].members.filter(item => records[item.name] !== undefined && isAlertingState(stateToValue(item.state), records[item.name]));
        const alertingNames = allAlerting.map(item => item.label);
        const nullItems = items[group].members.filter(item => item.isUninitialized);
        const nullItemNames = nullItems.map(item => item.label);
        rules.runRule(ruleID, {'alertItem':        record.name,
                               'alertState':       ''+state,
                               'isAlerting':       isAlerting,
                               'isInitialAlert':   isInitialAlert,
                               'threshItems':      allAlerting,
                               'threshItemLabels': alertingNames,
                               'nullItems':        nullItems,
                               'nullItemLabels':   nullItemNames}, true);
      } catch(e) {
        console.error('Error running rule ' + ruleID + '\n' + e);
      }
      console.debug('Rule ' + ruleID + ' has been called for ' + record.name);
    });
  }
  // Only rate limit the alert, always make the end alert call
  (isAlerting && record.rateLimit !== '') ? rl.run(throttle, record.rateLimit) : throttle();

}

/**
 * Creates the function that gets called by the loopingTimer for a given Item. The generated
 * function returns how long to wait for the next call (adjusted for DND) or null when it's
 * time to exit.
 *
 * @param {Object} Object containing alertTimer, endAlertTimer, alerted, alertState
 * @return {function} function that takes no arguments called by the looping timer
 */
var sendAlertGenerator = (record) => {
  return () => {
    const item = items[record.name];
    const currState = stateToValue(items[record.name].rawState);
    refreshRecord(record);

    // We can still get Multithreaded exceptions when calling another rule, this should reduce the occurance of that
    console.debug('Alert timer expired for ' + record.name + ' with dnd between ' + record.dndStart + ' and ' + record.dndEnd + ' and reminder period ' + record.remPeriod);
    let repeatTime = generateAlertTime(record.remPeriod, record.dndStart, record.dndEnd); // returns null if remPeriod is '', which cancels the loop

    // Call alert rule if still alerting
    if(isAlertingState(currState, record)) {
      console.debug(record.name + ' is still in an alerting state.');
      callRule(currState, record.alertRule, true, false, record);
      if(!record.alerted) record.alertState = currState;
      record.alerted = true;
      if(repeatTime === null) record.alertTimer = null; // clean up if no longer looping
      console.debug('Waiting until ' + repeatTime + ' to send reminder for ' + record.name);
      return repeatTime;
    }
    // no longer alerting, cancel the repeat, send an alert if configured
    else {
      console.debug(record.name + ' is no longer in an alerting state but timer was not cancelled, this should not happen');
      record.alertTimer = null;
      return null;
    }
  }
}

/**
 * Called when the Item event indicates that it's in an alerting state. If there isn't
 * already a looping timer running, create one to initially run at alertTime (adjusted
 * for DND) and repeat according to remPeriod. If dndStart is after dndEnd, the DND is
 * assumed to span midnight.
 *
 * @param {State|String} state state of the Item that generated the event
 * @param {Object} record contains alertTimer, endAlertTimer, and alerted flag
 */
var alerting = (state, record) => {
  console.debug(record.name + ' is in the alert state of ' + state);

  // Cancel the endAlertTimer if there is one
  if(record.endAlertTimer !== null) {
    console.debug('Cancelling endAlertTimer for ' + record.name);
    record.endAlertTimer.cancel();
    record.endAlertTimer = null;
  }

  // Set a timer for how long the Item needs to be in the alerting state before alerting.
  // If one is already set, ignore it
  let timeout = generateAlertTime(record.alertDelay, record.dndStart, record.dndEnd);
  if(timeout === null) timeout = 'PT0S'; // run now

  // First time the Item entered the alert state
  if(record.alertTimer === null && !record.isAlerting) {
    // Schedule the initAlertTimer first and it will run first
    console.debug('Calling the initial alert rule for ' + record.name);
    record.initAlertTimer = LoopingTimer();
    record.initAlertTimer.loop(() => {
      console.debug('Calling init alert rule for ' + record.name);
      callRule(state, record.initAlertRule, false, true, record);
      record.initAlertTimer = null;
      return null;
    }, generateAlertTime(time.toZDT(), record.dndStart, record.dndEnd));
    // Create the alert timer
    console.debug('Creating looping alert timer for ' + record.name + ' at ' + timeout);
    record.alertTimer = LoopingTimer();
    record.alertTimer.loop(sendAlertGenerator(record), timeout);
  }
  // Reschedule the alert timer
  else if(record.alertTimer !== null && record.reschedule) {
    console.debug('Rescheduling the timer for ' + record.name + ' at ' + timeout);
    record.alertTimer.timer.reschedule(time.toZDT(timeout));
  }
  // Do nothing
  else {
    console.debug(record.name + ' already has an alert timer or has already alerted, ignoring event.');
  }
}

/**
 * Applies the hysteresis and returns true if the curr value is different enough from the
 * alert value or if the calculation cannot be done because the three arguments are not
 * compatible.
 * @param {string|float|Quantity} curr current state
 * @param {string|float|Quantity} alert the state that was alerted
 * @param {string|float|hyst} hyst the hysteresis range
 * @return {boolean} true if curr is different from alert by hyst or more, or if the arguments are incompatable.
 */
var applyHyst = (curr, alert, hyst) => {
  console.debug('Applying hysteresis with: curr = ' + curr + ', alert = ' + alert + ', hyst = ' + hyst);

  // Quantity
  if(curr.unit !== undefined && alert.unit != undefined && hyst.unit !== undefined) {
    try {
      const delta = (curr.lessThan(alert)) ? alert.subtract(curr) : curr.subtract(alert);
      console.debug('Applying hysteresis using Quantities, delta = ' + delta + ' hystRange = ' + hyst);
      return delta.greaterThan(hyst);
    } catch(e) {
      console.error('Attempting to apply hysteresis with Quantities of incompatable units. Not applying hysteresis');
      return true;
    }
  }
  // Number
  else if(typeof curr !== 'string' && typeof alert !== 'string' && typeof hyst !== 'string') {
    curr = (curr.unit !== undefined) ? curr.float : curr;
    alert = (alert.unit !== undefined) ? alert.float : alert;
    hyst = (hyst.unit !== undefined) ? hyst.float : float;
    const delta = Math.abs(curr - alert);
    console.debug('Applying hysteresis using numbers, delta = ' + delta + ' hystRange = ' + hyst);
    return delta > hyst;
  }
  else {
    console.debug('Not all values are compatible, skipping hysteresis');
    return true;
  }
}
/**
 * Called when the Item event indicates that it is not in an alerting state.
 * Clean up the record a
 * @param {string|float|Quantity} state state that generated the event
 * @param {Object} record contains alertTimer, endAlertTimer, and alerted flag
 */
var notAlerting = (state, record) => {
  console.debug(record.name + "'s new state is " + state + ' which is no longer in the alerting state, previously alerted = ' + record.alerted);

  // Skip if we don't pass hysteresis
  if(record.alerted && !applyHyst(state, record.threshold, record.hysteresis)) {
    console.debug(record.name + ' did not pass hysteresis, remaining in alerting state');
    return;
  }

  // Cancel the initAlertTimer
  if(record.initAlertTimer !== null) {
    console.debug('Cancelling alert timer for ' + record.name);
    record.initAlertTimer.cancel();
    record.initAlertTimer = null;
  }

  // Cancel the alertTimer
  if(record.alertTimer !== null) {
    console.debug('Cancelling alertTimer for ' + record.name);
    record.alertTimer.cancel();
    record.alertTimer = null;
  }

  // Send alert if required
  if(record.endRule && record.alerted) {
    console.debug('Sending alert that ' + record.name + ' is no longer in the alerting state');
    // Schedule a timer if in DND, otherwise run now
    const scheduleTime =  generateAlertTime(time.toZDT(), record.dndStart, record.dndEnd);
    if(record.endAlertTimer === undefined || record.endAlertTimer === null) {
      record.endAlertTimer = LoopingTimer();
      record.endAlertTimer.loop(() => {
        console.debug('Calling end alert rule for ' + record.name);
        callRule(stateToValue(items[record.name].rawState), record.endRule, false, false, record);
        record.alerted = false;
        record.alertState = null;
        record.endAlertTimer = null;
        return null;
      },scheduleTime);
    }
    else {
      record.endAlertTimer.timer.reschedule(scheduleTime);
    }
  }
  else if(!record.endRule && record.alerted) {
    console.debug('No end alert rule is configured, exiting alerting for ' + record.name);
    record.alerted = false;
    record.alertState = null;
  }
  else if(!record.alerted) {
    console.debug('Exiting alerting state but alert was never sent, not sending an end alert for ' + record.name);
  }
  else {
    console.warn('We should not have reached this!');
  }
}

/**
 * Returns a function that executes the passed in comparison on two operands. If
 * both are numbers a numerical comparison is executed. Otherwise the operands are
 * converted to strings and a string comparison is done.
 *
 * @param {string} operator the comparison the that the returned function will execute
 * @return {function(a, b)} function tjat executes a number comparison if both operands are numbers, a string comparison otherwise
 */
var generateStandardComparison = (operator) => {
  return (a, b) => {
    let op = null;
    switch(operator) {
      case '==':
        op = (a, b) => a == b;
        break;
      case '!=':
        op = (a, b) => a != b;
        break;
      case '<' :
        op = (a, b) => a < b;
        break;
      case '<=':
        op = (a, b) => a <= b;
        break;
      case '>' :
        op = (a, b) => a > b;
        break;
      case '>=':
        op = (a, b) => a >=b;
        break;
    }
    if(isNaN(a) || isNaN(b)) {
      return op(''+a, ''+b); // convert to strings if both operands are not numbers
    }
    else {
      return op(a, b);
    }
  }
}

/**
 * Creates the custom comparison operator. If both operands are Quantities and they
 * have compatible units, the Quantity comparison will be returned. Otherwise a
 * standard comparison will be used.
 *
 * @param {string} operator the comparison operator
 * @return {function(a, b)} function that executes the right comparison operation based on the types of the operands
 */
var generateComparison = (operator) => {
  // Assume quantity, revert to standard if not or incompatible units
  return (a, b) => {
    let op = null;
    switch(operator) {
      case '==':
        op = (a, b) => a.equal(b);
        break;
      case '!=':
        op = (a, b) => !a.equal(b);
        break;
      case '<' :
        op = (a, b) => a.lessThan(b);
        break;
      case '<=':
        op = (a, b) => a.lessThanOrEqual(b);
        break;
      case '>' :
        op = (a, b) => a.greaterThan(b);
        break;
      case '>=':
        op = (a, b) => a.greaterThanOrEqual(b);
        break;
    }
    try {
      if(a.unit !== undefined && b.unit !== undefined) return op(a, b);
      else return generateStandardComparison(operator)(a, b);
    } catch(e) {
      // Both are Quantities but they have incompatible units
      return generateStandardComparison(operator)(a, b);
    }
  }
}

/**
 * Populate/refresh the record with any changes to parameters that may have been
 * made to the Item's metadata since the rule was first run.
 *
 * @param {Object} record contains all the settings and timners for an Item
 */
var refreshRecord = (record) => {
  // Metadata may have changed, update record with latest values
  console.debug('Populating record from Item metadata or rule defauls');
  const md = (items[record.name].getMetadata()[namespace] !== undefined) ? items[record.name].getMetadata()[namespace].configuration : {};
  console.debug('Converting threshold to value');
  record.threshold = stateToValue(thresholdStr);
  if(md['threshold'] !== undefined) record.threshold = stateToValue(md['threshold']);
  if(md['thresholdItem'] !== undefined) record.threshold = stateToValue(items[md['thresholdItem']].rawState);
  record.operator      = (md['operator'] !== undefined) ? md['operator'] : operator;
  record.invert        = (md['invert'] !== undefined) ? md['invert'] === true : invert;
  record.reschedule    = (md['reschedule'] !== undefined) ? md['reschedule'] === true : reschedule;
  record.compare       = generateComparison(record.operator);
  record.alertDelay    = (md['alertDelay'] !== undefined) ? md['alertDelay'] : defaultAlertDelay;
  record.remPeriod     = (md['remPeriod'] !== undefined) ? md['remPeriod'] : defaultRemPeriod;
  record.alertRule     = (md['alertRuleID'] !== undefined) ? md['alertRuleID'] : alertRuleUID;
  record.endRule       = (md['endRuleID'] !== undefined) ? md['endRuleID'] : endAlertUID;
  record.initAlertRule = (md['initAlertRuleID'] !== undefined) ? md['initAlertRuleID'] : initAlertRuleUID
  record.gatekeeper    = (md['gatekeeperDelay'] !== undefined) ? md['gatekeeperDelay'] : gkDelay;
  console.debug('Converting hysteresis to value');
  record.hysteresis    = stateToValue((md['hysteresis'] !== undefined) ? md['hysteresis'] : hystRange);
  record.rateLimt      = (md['rateLimit'] !== undefined) ? md['rateLimit'] : rateLimitPeriod;
  record.dndStart      = (md['dndStart'] !== undefined) ? md['dndStart'] : dndStart;
  record.dndEnd        = (md['dndEnd'] !== undefined) ? md['dndEnd'] : dndEnd;
  console.debug('Processing event for Item ' + record.name + ' with properties: \n'
                + '  Threshold          - ' + record.threshold + '\n'
                + '  Operator           - ' + record.operator + '\n'
                + '  Invert             - ' + record.invert + '\n'
                + '  Reschedule         - ' + record.reschedule + '\n'
                + '  Alert Delay        - ' + record.alertDelay + '\n'
                + '  Reminder Period    - ' + record.remPeriod + '\n'
                + '  Alert Rule ID      - ' + record.alertRule + '\n'
                + '  End Alert Rule ID  - ' + record.endRule + '\n'
                + '  Init Alert Rule ID - ' + record.initAlertRule + '\n'
                + '  Gatekeeper Delay   - ' + record.gatekeeper + '\n'
                + '  Hystersis          - ' + record.hysteresis + '\n'
                + '  Rate Limt          - ' + record.rateLimt + '\n'
                + '  DnD Start          - ' + record.dndStart + '\n'
                + '  DnD End            - ' + record.dndEnd);
}

/**
 * Process an Item event, checking to see if it is in an alerting state and calling
 * the alerting rule with repeats if configured. If it is no longer in an alerting
 * state and an alert was sent, call the end alerting rule if configured.
 *
 * @param {string} name the name of the Item
 * @param {string|float|Quantity} state the Item's current state
 */
var procEvent = (name, state) => {
//  const value = stateToValue(state);
  console.debug('Processing state ' + state + ' from ' + name);
  const records = cache.private.get('records', () => { return {}; });

    // Initialze the record in timers if one doesn't already exist or it's incomplete
//  if(records[name] === undefined
//     || records[name].alertTimer === undefined
//     || records[name].endAlertTimer === undefined
//     || records[name].initAlertTimer == undefined
//     || records[name].alerted === undefined) {
//    console.debug('Initializing record for ' + name);
//    records[name] = {name:          name,
//                     alertTimer:    (records[name] === undefined) ? null: records[name].alertTimer,
//                     endAlertTimer: (records[name] === undefined) ? null: records[name].endAlertTimer,
//                     initAlertTimer: (records[name] === undefined) ? null: records[name].initAlertTimer,
//                     alerted:       false};
//  }
  // Initialize the record in timers if one doesn't already exist
  if(records[name] === undefined) {
    console.debug('Initializing record for ' + name);
    records[name] = { name: name,
                      alertTimer: null,
                      endAlertTimer: null,
                      initAlertTimer: null,
                      alerted: false };
  }
  const record = records[name];

  refreshRecord(record);

  // Alerting state, set up an alert timer
  if(isAlertingState(state, record)) {
    alerting(state, record);
  }
  // Not alerting, cancel the timer and alert if configured
  else {
    notAlerting(state, record);
  }
}

/**
 * @param {string} op candidate operator
 * @return {boolen} true if op is one of ==, !=, <, <=, >, >=
 */
var validateOperator = (op) => {
  return ['==', '!=', '<', '<=', '>', '>='].includes(op);
}

/**
 * @param {string} dur candidate ISO8601 duration
 * @return {boolean} true if dur can be parsed into a duration
 */
var validateDuration = (dur) => {
  try {
    if(dur !== '') time.Duration.parse(dur);
    return true
  } catch(e) {
    console.error('Failed to parse duration ' + dur + ': ' + e);
    return false;
  }
}

/**
 * @param {string} t candidate time
 * @return {boolean} true if t can be converted into a valid datetime
 */
var validateTime = (t) => {
  try {
    const militaryHrRegex = /^(0?[0-9]|1[0-9]|2[0-3])(:[0-5][0-9]){1,2}$/;
    const meridianHrRegex = /^(0?[0-9]|1[0-2])(:[0-5][0-9]){1,2} ?[a|p|A|P]\.?[m|M]\.?$/;
    if(militaryHrRegex.test(t) || meridianHrRegex.test(t)) {
      time.toZDT(t);
      return true;
    } else {
      return false;
    }
  } catch(e) {
    console.error('Failed to parse time ' + t + ': ' + e);
    return false;
  }
}

/**
 * @param {string} id candidate rule id
 * @return {boolean} true if the rule exists and is enabled
 */
var validateRule = (id) => {
  try {
    if(!rules.isEnabled(id)) {
      console.error('Rule ' + id + ' is disabled');
      return false;
    }
    return true;
  } catch(e) {
    console.error('Rule ' + id + ' does not exist');
    return false;
  }
}

/**
 * @param {string} h candidate hysteresis
 * @return {boolean} true if h is either a number or Quantity
 */
var validateHysteresis = (h) => {
  const parsed = stateToValue(h);
  return !isNaN(parsed) || parsed.unit !== undefined;
}

/**
 * Analyzes the rule properties and Items to verify that the config will work.
 */
var init = () => {

  console.debug( 'Rule config defaults:\n'
               + '  Group                     - ' + group + '\n'
               + '  Threhsold                 - ' + thresholdStr + '\n'
               + '  Operator                  - ' + operator + '\n'
               + '  Invert Operator           - ' + invert + '\n'
               + '  Reschedule                - ' + reschedule + '\n'
               + '  Default Alert Delay       - ' + defaultAlertDelay + '\n'
               + '  Default Reminder Duration - ' + defaultRemPeriod + '\n'
               + '  DND Start                 - ' + dndStart + '\n'
               + '  DND End                   - ' + dndEnd + '\n'
               + '  Alert Rule                - ' + alertRuleUID + '\n'
               + '  End Alert Rule            - ' + endAlertUID + '\n'
               + '  Alert Group               - ' + group + '\n'
               + '  Alert Items               - ' + items[group].members.map(i => i.name).join(', ') + '\n'
               + '  Gatekeeper Delay          - ' + gkDelay + '\n'
               + '  Rate Limit                - ' + rateLimitPeriod);

  var error = false;
  var warning = false;
  const allItems = items[group].members;

  console.info('Cancelling any running timers');
  const records = cache.private.get('records');
  if(records !== null) {
    Object.values(records).forEach(record => {
      if(record.alertTimer !== null && record.alertTimer !== undefined){
        console.info(record.name + ' has an alert timer scheduled, cancelling now.');
        record.alertTimer.cancel();
        record.alertTimer = null;
      }
      if(record.endAlertTimer !== null && record.endAlertTimer !== undefined) {
        console.info(record.name + ' has an end alert timer scheduled, cancelling now.');
        record.endAlertTimer.cancel();
        record.endAlertTimer = null;
      }
    });
  }

  // Inform if the threshold is UnDefType
  if(thresholdStr === 'UnDefType') {
    console.info('Threshold is UnDefType, this will cause Item states of NULL and UNDEF to be converted to UnDefType for comparisons.');
  }

  // Error if the Group has QuantityTypes but thresholdStr is not
  const quantityTypes = allItems.filter(item => item.quantityState !== null);
  if(quantityTypes.length > 0 && thresholdStr !== 'UnDefType') {
    try {
      if(!thresholdStr.includes(' ')) {
        warn = true;
        console.warn(group + ' contains Quantity states by thresholdStr ' + thresholdStr + ' does not have units, comparison will revert to number or string comparison.');
      }
      else {
        Quantity(thresholdStr);
      }
    } catch(e) {
      warning = true;
      console.warn(group + ' contains Quantity states but thresholdStr ' + thresholdStr + ' cannot be converted to a Quantity, comparison will default to a String comparsion');
    }
  }

  // Error if the Group has more than one type of Item
  const itemTypes = allItems.filter(item => item.rawItem.class.name === allItems[0].rawItem.class.name);
  if(itemTypes.length != allItems.length) {
    warn = true;
    console.warn(group + ' has a mix of Item types');
  }

  // Warn if thresholdStr is empty string, there are cases where that could be OK but most of
  // the time it isn't.
  if(thresholdStr == '') {
    warning = true;
    console.warn('Alert State is an empty String, is that intended?');
  }

  // Verify the operator is valid
  if(!validateOperator(operator)) {
    error = true;
    console.error('Invalid operator ' + operator);
  }

  // Inform that there is no default alert delay configured, there will be no pause before alerting
  if(defaultAlertDelay == '') {
    console.info('Items without ' + namespace + ' alertDelay metadata will alert immediately');
  } else if(!validateDuration(defaultAlertDelay)){
    error = true;
    console.error('The default alert delay ' + defaultAlertDelay + ' is not a parsable ISO8601 duration string');
  }

  // Inform that there is no default reminder period configured, there will be no repreated alerts
  if(defaultRemPeriod == '') {
    console.info('Items without ' + namespace + ' remPeriod metadata will not repeat alerts');
  } else if(!validateDuration(defaultRemPeriod)){
    error = true;
    console.error('The default reminder period ' + defaultRemPeriod + ' is not a parsable ISO8601 duration string');
  }

  // Inform if both of the DND times are not set
  // Error if one but not the other is defined
  // Error if either cannot be parsed into a ZDT
  if(dndStart == '' && dndEnd == '') {
    console.info('DND Start and End are empty, no DND period will be applied');
  }
  else if(dndStart == '' && dndEnd != '') {
    error = true;
    console.error('DND Start is defined but DND End is not.');
  }
  else if(dndStart != '' && dndEnd == '') {
    error = true;
    console.error('DND Start is not defined but DND End is.')
  }
  else if(dndStart != '' && !validateTime(dndStart)) {
    error = true;
    console.error('DND Start ' + dndStart + ' is not parsable into a time');
  }
  else if(dndEnd != '' && !validateTime(dndEnd)) {
    error = true;
    console.error('DND End ' + dndEnd + ' is not parsable into a time');
  }

  // Error is no alert rule is configured or the rule is disabled or does not exist
  if(alertRuleUID == '') {
    error = true;
    console.error('No alert rule is configured!');
  } else if(!validateRule(alertRuleUID)) {
    error = true;
    console.error('Alert rule ' + alertRuleUID + ' is disabled or does not exist');
  }

  // Inform if the end alert rule is not configured
  // Error if it is configured but it is disabled or does not exist
  if(endAlertUID == '') {
    console.info('No end alert rule configured, no rule will be called when alerting ends');
  }
  else if(!validateRule(endAlertUID)) {
    error = true;
    console.error('End alert rule ' + endAlertUID + ' is diabled or does not exist');
  }

  // Inform if the initial alert rule is not configured
  // Error if it is configured but it is disabled or does not exist
  if(initAlertRuleUID == '') {
    console.info('No initial alert rule configured, no rule will be called when the alert state is first detected');
  }
  else if(!validateRule(initAlertRuleUID)) {
    error = true;
    console.error('Initial alert rule ' + initAlertRuleUID + ' is disable or does not exist');
  }

  // Validate hysteresis
  if(hystRange !== '' && !validateHysteresis(hystRange)) {
    error = true;
    console.error('Hysteresis ' + hystRange + ' is not a number nor Quantity');
  }

  // Warn if there are QuantityTypes but hystRange does not have units
  if(hystRange !== '' && quantityTypes.length > 0) {
    if(!hystRange.includes(' ')) {
      warning = true;
      console.warn(group + ' has QuantityTypes but hystRange ' + hystRange + ' does not have units.');
    }
    else {
      try {
        Quantity(hystRange);
      } catch(e) {
        warning = true;
        console.warn(group + ' has QuantityTypes by hystRange ' + hystRange + ' cannot be parsed into a Quantity.');
      }
    }
  }

  // Validate rateLimit Period and warn if less than gkDelay
  if(rateLimitPeriod !== '' && !validateDuration(rateLimitPeriod)) {
    error = true;
    console.error('A rate limit was provided but ' + rateLimitPeriod + ' is not a parsable ISO8601 duration string.');
  }
  if(rateLimitPeriod !== '' && gkDelay) {
    if(time.Duration.parse(rateLimitPeriod).lessThan(time.Duration.ofMillis(gkDelay))) {
      warning = true;
      console.warn('Both rate limit and gatekeeper delay are defined but gatekeeper delay is greater than the rate limit. The rate limit should be significantly larger.');
    }
  }

  // Inform if none of the Items have namespace metadata
  const noMetadata = allItems.filter(item => item.getMetadata()[namespace] === undefined);
  if(noMetadata.length > 0) {
    console.info('These Items do not have ' + namespace + ' metadata and will use the default properties defined in the rule: '
                 + noMetadata.map(i => i.name).join(', '));
  }

  // Validate Item metadata
  allItems.filter(item => item.getMetadata()[namespace]).forEach(item => {
    const md = item.getMetadata()[namespace].configuration;
    console.debug('Metadata for Item ' + item.name + '\n' + Object.keys(md).map(prop => prop + ': ' + md[prop]).join('\n'));

    // Anything is OK for threshold
    if(md['thresholdItem'] !== undefined) {
      const threshItem = md['thresholdItem'];
      if(md['threshold'] !== undefined) {
        error = true;
        console.error('Item ' + item.name + ' has both thershold and thresholdItem defined in ' + namespace + ' metadata');
      }
      if(items[threshItem] === undefined || items[threshItem] === null) {
        error = true;
        console.error('Item ' + item.name + ' defines thresholdItem ' + threshItem + ' which does not exist');
      } else if(item.quantityState !== null && items[threshItem].quantityState === null){
        error = true;
        console.error('Item ' + item.name + ' is a Quantity but thresholdItem ' + threshItem + ' is not');
      } else if(item.quantityState === null && items[threshItem].quantityState !== null) {
        error = true;
        console.error('Item ' + item.name + ' is not a Quantity but thresholdItem ' + threshItem + ' is');
      } else if(item.numericState !== null && items[threshItem].numericState === null) {
        error = true;
        console.error('Item ' + item.name + ' is a number but thresholdItem ' + threshItem + ' is not');
      } else if(item.numericState === null && items[threshItem].numericState !== null) {
        error = true;
        console.error('Item ' + item.name + ' is not a number but thresholdItem ' + threshItem + ' is');
      }
    }
    if(md['operator'] !== undefined && !validateOperator(md['operator'])) {
      error = true;
      console.error('Item ' + item.name + ' has an invalid operator ' + md['operator'] + ' in ' + namespace + ' metadata');
    }
    if(md['invert'] !== undefined && (md['invert'] !== true && md['invert'] !== false)) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsible invert ' + md['invert'] + ' in ' + namespace + ' metadata');
    }
    if(md['reschedule'] !== undefined && (md['reschedule'] !== true && md['reschedule'] !== false)) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsible reschedule ' + md['reschedule'] + ' in ' + namespace + ' metadata');
    }
    if(md['alertDelay'] !== undefined && !validateDuration(md['alertDelay'])) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsable alertDelay ' + md['alertDelay'] + ' in ' + namespace + ' metadata');
    }
    if(md['remPeriod'] !== undefined && !validateDuration(md['remPeriod'])) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsable remPeriod ' + md['remPeriod'] + ' in ' + namespace + ' metadata');
    }
    if(md['alertRuleID'] !== undefined && !validateRule(md['alertRuleID'])) {
      error = true;
      console.error('Item ' + item.name + ' has an invalid alertRuleID ' + md['alertRuleID'] + ' in ' + namespace + ' metadata');
    }
    if(md['endRuleID'] !== undefined && !validateRule(md['endRuleID'])) {
      error = true;
      console.error('Item ' + item.name + ' has an invalid endRuleID ' + md['endRuleID'] + ' in ' + namespace + ' metadata');
    }
    if(md['initAlertRuleID'] !== undefined && !validateRule(md['initAlertRuleID'])) {
      error = true;
      console.error('Item ' + item.name + ' has an invalid initAlertRuleID ' + md['initAlertRuleID'] + ' in ' + namespace + ' metadata');
    }
    if(md['gatekeeperDelay'] !== undefined && isNaN(md.gatekeeperDelay)) {
      error = true;
      console.error('Item ' + item.name + ' has a non-numerical gatekeeperDelay ' + md['gatekeeperDelay'] + ' in ' + namespace + ' metadata');
    }
    if(md['gatekeeperDelay'] !== undefined && md['gatekeeperDelay'] < 0) {
      warning = true;
      console.warn('Item ' + item.name + ' has a negative gatekeeperDelay ' + md['gatekeeperDelay'] + ' in ' + namespace + ' metadata');
    }
    if(md['hysteresis'] !== undefined && !validateHysteresis(md['hysteresis'])) {
      error = true;
      console.error('Item ' + item.name + ' has a non-numerical nor Quantity hystersis ' + md['hysteresis'] + ' in' + namespace + ' metadata');
    }
    else if(md['hysteresis'] && item.quantityState !== null && stateToValue(md['hysteresis']).unit === undefined) {
      warn = true;
      console.warn('Item ' + item.name + ' has a Quantity but hystereis ' + md['hysteresis'] + ' is not a Quantity');
    }
    else if(md['hysteresis'] && item.quantityState !== null && stateToValue(md['hysteresis']).unit !== undefined) {
      try {
        item.quantityState.equal(stateToValue(md['hysteresis']));
      } catch(e) {
        error = true;
        console.error('Item ' + item.name + ' has a hysteresis ' + md['hysteresis'] + ' with units incompatible with ' + item.quantityState.unit);
      }
    }
    if(md['rateLimit'] !== undefined && !validateDuration(md['rateLimit'])) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsable rateLimit ' + md['rateLimit'] + ' in ' + namespace + ' metadata');
    }
    if(md['dndStart'] !== undefined && !validateTime(md['dndStart'])) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsable dndStart time ' + md['dndStart'] + ' in ' + namespace + ' metadata');
    }
    if(md['dndEnd'] !== undefined && !validateTime(md['dndEnd'])) {
      error = true;
      console.error('Item ' + item.name + ' has an unparsable dndEnd time ' + md['dndEnd'] + ' in ' + namespace + ' metadata');
    }
    if((md['dndStart'] === undefined && md['dndEnd'] !== undefined)
       || (md['dndStart'] !== undefined && md['dndEnd'] === undefined)) {
      error = true;
      console.error('Item ' + item.name + ' one but not both of dndStart and dndEnd defined on ' + namespace + ' metadata');
    }

    // Warn if metadata is present but none of the known configuration parameters are
    if(!['threshold', 'thresholdItem', 'operator', 'invert', 'alertDelay', 'remPeriod', 'alertRuleID', 'endRuleID', 'gatekeeperDelay', 'hysteresis', 'rateLimit', 'dndStart', 'dndEnd']
       .some(name =>  md[name] !== undefined)) {
      warning = true;
      console.warn('Item ' + item.name + ' has ' + namespace + ' metadata but does not have any known configuration property used by this rule');
    }
  });


  if(error) console.error('Errors were found in the configuration, see above for details.')
  else if(warning) console.warn('Warnings were found in the configuration, see above for details. Warnings do not necessarily mean there is a problem.')
  else console.info('Threshold Alert configs check out as OK')
}
//~~~~~~~~~~~~~ Body
// If triggered by anything other than an Item event, check the config
// Otherwise process the event to see if alerting is required
if(this.event === undefined) {
  console.debug('Rule triggered without an event, checking config.');
  init();
}
else {
  switch(event.type) {
    case 'ItemStateEvent':
    case 'ItemStateUpdatedEvent':
    case 'ItemStateChangedEvent':
      console.loggerName = loggerBase+'.'+event.itemName;
      console.debug('Processing an Item event');
      procEvent(event.itemName, stateToValue(event.itemState));
      break;
    default:
      console.info('Rule triggered without an Item event, ' + event.type + ' checking the rule config');
      //cache.private.clear();
      init();
  }
}

rlkoshak · November 4, 2024, 9:25pm

I don’t see the line that needs to be edited to change the logging. The line to uncomment is line number 7:

// Version 1.0
var {helpers, LoopingTimer, Gatekeeper, timeUtils, RateLimit} = require('openhab_rules_tools');
var {DecimalType, QuantityType, PercentType} = require('@runtime');

var loggerBase = 'org.openhab.automation.rules_tools.Threshold Alert.'+ruleUID;
console.loggerName = loggerBase;
//osgi.getService('org.apache.karaf.log.core.LogService').setLevel(console.loggerName, 'DEBUG'); // <------ Uncomment this one

helpers.validateLibraries('4.1.0', '2.0.3');

console.debug('Starting threshold alert');

ErikDB · November 4, 2024, 9:26pm

I had only pasted my alterations - the full script is there now.

rlkoshak · November 4, 2024, 9:34pm

But the error was comming from the line you didn’t post before. That was my point.

But again, I don’t know why this would fail with that error. I’ve never seen that error before. I’m unable to reproduce it.

But don’t forget, you need to

uncomment line 7
save
manually run the rule once
comment the line back out
save
manually run the rule once

When that line runs, it actually causes a change to the log4j.xml config file. If the file happens to be being written to at that time you might wipe out the whole logging config. You do not want this line of code to run every time the rule runs. This is even more true if you have more than one rule that sets a logger level in this way.

ErikDB · November 4, 2024, 9:39pm

This is where the error popped up…

By the way, this is what my log4j.xml looks like, if that might give a clue…?

<?xml version="1.0" encoding="UTF-8" standalone="no"?><Configuration monitorInterval="10">

	<Appenders>
		<!-- Console appender not used by default (see Root logger AppenderRefs) -->
		<Console name="STDOUT">
			<PatternLayout pattern="%d{HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
		</Console>

		<!-- Rolling file appender -->
		<RollingFile fileName="${sys:openhab.logdir}/openhab.log" filePattern="${sys:openhab.logdir}/openhab.log.%i.gz" name="LOGFILE">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<OnStartupTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="16 MB"/>
			</Policies>
			<DefaultRolloverStrategy max="7"/>
		</RollingFile>

		<!-- Event log appender -->
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/events.log" filePattern="${sys:openhab.logdir}/events.log.%i.gz" name="EVENT">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
			<Policies>
				<OnStartupTriggeringPolicy/>
				<SizeBasedTriggeringPolicy size="16 MB"/>
			</Policies>
			<DefaultRolloverStrategy max="7"/>
		</RollingRandomAccessFile>

		<!-- OSGi appender -->
		<PaxOsgi filter="*" name="OSGI"/>

		<!-- Zelfgemaakte appender voor Unifi Protect-binding -->
		<!-- Het loggen van de Unifi Protect-binding wordt (voorlopig?) stopgezet. TOCH EVEN NIET...-->

		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/unifiprotect.log" filePattern="${sys:openhab.logdir}/unifiprotect.log.%i" name="UNIFIPROTECT">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
				<Policies>
					<OnStartupTriggeringPolicy/>
					<SizeBasedTriggeringPolicy size="100 MB"/>
				</Policies>
		</RollingRandomAccessFile>

		<!-- -->
		
		<!-- Zelfgemaakte appender voor EnOcean-binding -->
		<!-- Het loggen van de EnOcean-binding wordt (voorlopig?) stopgezet. TOCH NIET! -->

		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/enoceanbinding.log" filePattern="${sys:openhab.logdir}/enoceanbinding.log.%i" name="ENOCEANBINDING">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
				<Policies>
					<OnStartupTriggeringPolicy/>
					<SizeBasedTriggeringPolicy size="100 MB"/>
				</Policies>
		</RollingRandomAccessFile>

		<!-- -->

		<!-- Zelfgemaakte appender voor Shelly-binding -->
		<!-- Het loggen van de Shelly-binding wordt (voorlopig?) stopgezet.

		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/shellybinding.log" filePattern="${sys:openhab.logdir}/shellybinding.log.%i" name="SHELLYBINDING">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
				<Policies>
					<OnStartupTriggeringPolicy/>
					<SizeBasedTriggeringPolicy size="100 MB"/>
				</Policies>
		</RollingRandomAccessFile>

		-->

		<!-- Zelfgemaakte appender voor ESPHome-binding -->
		<!-- Het loggen van de ESPHome-binding wordt (voorlopig?) stopgezet.
		
		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/esphomebinding.log" filePattern="${sys:openhab.logdir}/esphomebinding.log.%i" name="ESPHOMEBINDING">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
				<Policies>
					<OnStartupTriggeringPolicy/>
					<SizeBasedTriggeringPolicy size="100 MB"/>
				</Policies>
		</RollingRandomAccessFile>

		-->


	</Appenders>

	<Loggers>
		<!-- Root logger configuration -->
		<Root level="WARN">
			<AppenderRef ref="LOGFILE"/>
			<AppenderRef ref="OSGI"/>
		</Root>

		<!-- Karaf Shell logger -->
		<Logger level="OFF" name="org.apache.karaf.shell.support">
			<AppenderRef ref="STDOUT"/>
		</Logger>

		<!-- openHAB specific logger configuration -->

		<Logger level="INFO" name="org.openhab"/>

		<Logger level="ERROR" name="openhab.event.ItemStateEvent"/>
		<Logger level="WARN" name="openhab.event.ItemStateUpdatedEvent"/>
		<Logger level="ERROR" name="openhab.event.GroupStateUpdatedEvent"/>
		<Logger level="ERROR" name="openhab.event.ItemAddedEvent"/>
		<Logger level="ERROR" name="openhab.event.ItemRemovedEvent"/>
		<Logger level="ERROR" name="openhab.event.ItemChannelLinkAddedEvent"/>
		<Logger level="ERROR" name="openhab.event.ItemChannelLinkRemovedEvent"/>
		<Logger level="ERROR" name="openhab.event.ChannelDescriptionChangedEvent"/>
		<Logger level="ERROR" name="openhab.event.ThingStatusInfoEvent"/>
		<Logger level="ERROR" name="openhab.event.ThingAddedEvent"/>
		<Logger level="ERROR" name="openhab.event.ThingUpdatedEvent"/>
		<Logger level="ERROR" name="openhab.event.ThingRemovedEvent"/>
		<Logger level="ERROR" name="openhab.event.InboxUpdatedEvent"/>
		<Logger level="ERROR" name="openhab.event.RuleStatusInfoEvent"/>
		<Logger level="ERROR" name="openhab.event.RuleAddedEvent"/>
		<Logger level="ERROR" name="openhab.event.RuleRemovedEvent"/>
		<Logger level="ERROR" name="openhab.event.StartlevelEvent"/>
		<Logger level="ERROR" name="openhab.event.AddonEvent"/>

		<Logger additivity="false" level="INFO" name="openhab.event">
			<AppenderRef ref="EVENT"/>
			<AppenderRef ref="OSGI"/>
		</Logger>

		<Logger level="ERROR" name="javax.jmdns"/>
		<Logger level="ERROR" name="org.jupnp"/>

		<!-- This suppresses all Maven download issues from the log when doing feature installations -->
		<!-- as we are logging errors ourselves in a nicer way anyhow. -->
		<Logger level="ERROR" name="org.ops4j.pax.url.mvn.internal.AetherBasedResolver"/>

		<!-- Filters known issues of pax-web (issue link to be added here). -->
		<!-- Can be removed once the issues are resolved in an upcoming version. -->
		<Logger level="OFF" name="org.ops4j.pax.web.pax-web-runtime"/>

		<!-- Filters known issues of lsp4j, see -->
		<!-- https://github.com/eclipse/smarthome/issues/4639 -->
		<!-- https://github.com/eclipse/smarthome/issues/4629 -->
		<!-- https://github.com/eclipse/smarthome/issues/4643 -->
		<!-- Can be removed once the issues are resolved in an upcoming version. -->
		<Logger level="OFF" name="org.eclipse.lsp4j"/>

		<!-- Filters warnings for events that could not be delivered to a disconnected client. -->
		<Logger level="ERROR" name="org.apache.cxf.jaxrs.sse.SseEventSinkImpl"/>

		<!-- Filters warnings from broken connections during startup -->
		<!-- https://github.com/openhab/openhab-core/issues/2998 -->
		<Logger level="ERROR" name="org.apache.cxf.phase.PhaseInterceptorChain"/>

		<!-- Filters known issues of KarServiceImpl, see -->
		<!-- https://github.com/openhab/openhab-distro/issues/519#issuecomment-351944506 -->
		<!-- Can be removed once the issues are resolved in an upcoming version. -->
		<Logger level="ERROR" name="org.apache.karaf.kar.internal.KarServiceImpl"/>

		<!-- Filters warnings about unavailable ciphers when JCE is not installed, see -->
		<!-- https://github.com/openhab/openhab-distro/issues/999 -->
		<Logger level="ERROR" name="org.apache.karaf.shell.ssh.SshUtils"/>

		<!-- Filters known issues of javax.mail, see -->
		<!-- https://github.com/openhab/openhab-addons/issues/5530 -->
		<Logger level="ERROR" name="javax.mail"/>

		<!-- Filters disconnection warnings of the ChromeCast Java API, see -->
		<!-- https://github.com/openhab/openhab-addons/issues/3770 -->
		<Logger level="ERROR" name="su.litvak.chromecast.api.v2.Channel"/>

		<!-- Added by Karaf to prevent debug logging loops, see -->
		<!-- https://issues.apache.org/jira/browse/KARAF-5559 -->
		<Logger level="ERROR" name="org.apache.sshd"/>
		<Logger level="OFF" name="org.openhab.binding.enocean"/>
		<Logger name="org.openhab.binding.shelly"/>

		<!-- Zelfgemaakte logger voor Unifi Protect-binding -->
		<!-- Het loggen van de Unifi Protect-binding wordt (voorlopig?) stopgezet. TOCH EVEN NIET... -->

		<Logger additivity="false" level="TRACE" name="org.openhab.binding.unifiprotect">
			<AppenderRef ref="UNIFIPROTECT"/>
		</Logger>

		<!-- -->

		<!-- Zelfgemaakte logger voor EnOcean-binding -->
		<!-- Het loggen van de EnOcean-binding wordt (voorlopig?) stopgezet. TOCH NIET! -->
		
		<Logger additivity="false" level="TRACE" name="org.openhab.binding.enocean">
			<AppenderRef ref="ENOCEANBINDING"/>
		</Logger>

		<!-- -->

		<!-- Zelfgemaakte logger voor Shelly-binding -->
		<!-- Het loggen van de Shelly-binding wordt (voorlopig?) stopgezet.

		<Logger additivity="false" level="TRACE" name="org.openhab.binding.shelly">
			<AppenderRef ref="SHELLYBINDING"/>
		</Logger>

		-->

		<!-- Zelfgemaakte logger voor ESPHome-binding -->
		<!-- Het loggen van de ESPHome-binding wordt (voorlopig?) stopgezet.

		<Logger additivity="false" level="TRACE" name="no.seime.openhab.binding.esphome">
			<AppenderRef ref="ESPHOMEBINDING"/>
		</Logger>

		-->

	</Loggers>

</Configuration>

rlkoshak · November 4, 2024, 9:51pm

I don’t know what could cause this (maybe the permissions on log4j2.xml is such that the openhab user cannot write to the file), I cannot reproduce it, and you’ve at least three other ways to set the logger level:

edit log4j2.xml yourself
set from the karaf console
from the API explorer

This one may just have to remain a mystery.

Just take note that loggerBase has the name of the logger:

org.openhab.automation.rules_tools.Threshold Alert.<ruleUID>

Yes, there’s a space between “Threhold” and “Alert”

ErikDB · November 4, 2024, 10:10pm

openhab> log:set DEBUG org.openhab.automation.rules_tools.Threshold Alert.haarden-procesbescherming-UIT
Error executing command log:set: too many arguments specified

<?xml version="1.0" encoding="UTF-8" standalone="no"?><Configuration monitorInterval="10">

	<Appenders>
		[...]
                <!-- Zelfgemaakte appender voor haarden-procesbescherming-UIT-regel -->

		<RollingRandomAccessFile fileName="${sys:openhab.logdir}/haarden-procesbescherming-UIT.log" filePattern="${sys:openhab.logdir}/haarden-procesbescherming-UIT.log.%i" name="HAARDENTHRESHOLD">
			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n"/>
				<Policies>
					<OnStartupTriggeringPolicy/>
					<SizeBasedTriggeringPolicy size="100 MB"/>
				</Policies>
		</RollingRandomAccessFile>

	</Appenders>

	<Loggers>
		[...]
		<!-- Zelfgemaakte logger voor ESPHome-binding -->
		
		<Logger additivity="false" level="DEBUG" name="org.openhab.automation.rules_tools.Threshold Alert.haarden-procesbescherming-UIT">
			<AppenderRef ref="HAARDENTHRESHOLD"/>
		</Logger>


	</Loggers>

</Configuration>

This seems to work.

rlkoshak · November 4, 2024, 10:13pm

Hmmmm. Put the logger name in quotes. It may not like the space in the logger name. Technically it’s allowed but it might be an edge case that was not planned for by tghe karaf developers.

If that doesn’t work, you probably only have this one rule so if you change the logger level for org.openhab.automation.rules_tools that will catch this rule.

In future updates I’ll take the spaces out of the logger names for my rule templates so this is easier to deal with in the future.

ErikDB · November 4, 2024, 10:16pm

Of course… I could’ve thought of that myself…

ErikDB · November 5, 2024, 6:53pm

2024-11-05 16:43:33.413 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 16:43:33.413 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing an Item event
2024-11-05 16:43:33.413 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 16:43:33.413 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 16:43:33.413 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 s from haard_salon_procesbeschermingstimer
2024-11-05 16:43:33.413 [DEBUG] [.haard_salon_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - Converting threshold to value
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 16:43:33.414 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state  of type string
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a string: 
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_salon_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - Result is true
2024-11-05 16:43:33.415 [DEBUG] [.haard_salon_procesbeschermingstimer] - haard_salon_procesbeschermingstimer is in the alert state of 0 s
2024-11-05 16:43:33.419 [DEBUG] [.haard_salon_procesbeschermingstimer] - Calling the initial alert rule for haard_salon_procesbeschermingstimer
2024-11-05 16:43:33.425 [DEBUG] [.haard_salon_procesbeschermingstimer] - Creating looping alert timer for haard_salon_procesbeschermingstimer at 2024-11-05T16:43:35.415+01:00[SYSTEM]
2024-11-05 16:43:33.446 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 16:43:33.446 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing an Item event
2024-11-05 16:43:33.446 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 16:43:33.446 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 16:43:33.446 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s from haard_eetkamer_procesbeschermingstimer
2024-11-05 16:43:33.446 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_eetkamer_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:33.447 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_eetkamer_procesbeschermingstimer is in the alert state of 0 s
2024-11-05 16:43:33.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling the initial alert rule for haard_eetkamer_procesbeschermingstimer
2024-11-05 16:43:33.454 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Creating looping alert timer for haard_eetkamer_procesbeschermingstimer at 2024-11-05T16:43:35.447+01:00[SYSTEM]
2024-11-05 16:43:33.525 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling init alert rule for haard_salon_procesbeschermingstimer
2024-11-05 16:43:33.526 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - No rule ID passed, ignoring
2024-11-05 16:43:33.555 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling init alert rule for haard_eetkamer_procesbeschermingstimer
2024-11-05 16:43:33.555 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - No rule ID passed, ignoring
2024-11-05 16:43:35.416 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 16:43:35.417 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 16:43:35.417 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 16:43:35.419 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 16:43:35.420 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.420 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.420 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.420 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 16:43:35.420 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Alert timer expired for haard_salon_procesbeschermingstimer with dnd between 00:00 and 00:00 and reminder period 
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Timeout  is not valid, using null
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_salon_procesbeschermingstimer is still in an alerting state.
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling haard_eetkamer_procesbescherming_UIT with alertItem=haard_salon_procesbeschermingstimer, alertState=0 s, isAlerting=true, and initial alert false
2024-11-05 16:43:35.423 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.423 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.423 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.423 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.424 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.426 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Rule haard_eetkamer_procesbescherming_UIT has been called for haard_salon_procesbeschermingstimer
2024-11-05 16:43:35.428 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Waiting until null to send reminder for haard_salon_procesbeschermingstimer
2024-11-05 16:43:35.448 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 16:43:35.448 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 16:43:35.448 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 16:43:35.450 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_eetkamer_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Alert timer expired for haard_eetkamer_procesbeschermingstimer with dnd between 00:00 and 00:00 and reminder period 
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Timeout  is not valid, using null
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_eetkamer_procesbeschermingstimer is still in an alerting state.
2024-11-05 16:43:35.451 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling haard_eetkamer_procesbescherming_UIT with alertItem=haard_eetkamer_procesbeschermingstimer, alertState=0 s, isAlerting=true, and initial alert false
2024-11-05 16:43:35.452 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Waiting until null to send reminder for haard_eetkamer_procesbeschermingstimer
2024-11-05 16:43:35.530 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.530 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.530 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.531 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.531 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.532 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:43:35.532 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:43:35.532 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:43:35.532 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 16:43:35.533 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 16:43:35.536 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Rule haard_eetkamer_procesbescherming_UIT has been called for haard_eetkamer_procesbeschermingstimer
2024-11-05 16:51:12.348 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 16:51:12.349 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing an Item event
2024-11-05 16:51:12.350 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 10 of type object
2024-11-05 16:51:12.350 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 10
2024-11-05 16:51:12.350 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 10 s from haard_eetkamer_procesbeschermingstimer
2024-11-05 16:51:12.351 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 16:51:12.353 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 16:51:12.354 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 16:51:12.354 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 16:51:12.354 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 16:51:12.355 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 16:51:12.355 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 16:51:12.355 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 16:51:12.355 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 16:51:12.356 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_eetkamer_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 16:51:12.356 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 10 s == 0 s
2024-11-05 16:51:12.357 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is false
2024-11-05 16:51:12.357 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_eetkamer_procesbeschermingstimer's new state is 10 s which is no longer in the alerting state, previously alerted = true
2024-11-05 16:51:12.358 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Applying hysteresis with: curr = 10 s, alert = 0 s, hyst = 
2024-11-05 16:51:12.358 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Not all values are compatible, skipping hysteresis
2024-11-05 16:51:12.358 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - No end alert rule is configured, exiting alerting for haard_eetkamer_procesbeschermingstimer

Script haard_eetkamer_procesbescherming_UIT is called (because haard_eetkamer_procesbeschermingstimer read 0 s for at least two seconds). But script haard_salon_procesbescherming_UIT was not called (although haard_eetkamer_procesbeschermingstimer also read 0 s for at least two seconds)…?

Also, there seems to be a mixup, where haard_eetkamer_procesbeschermingstimer is the triggering item, but the rule for haard_salon_procesbeschermingstimer is called? I suppose this is where it goes wrong?

2024-11-05 16:43:33.525 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling init alert rule for haard_salon_procesbeschermingstimer
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties:
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Alert timer expired for haard_salon_procesbeschermingstimer with dnd between 00:00 and 00:00 and reminder period 
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_salon_procesbeschermingstimer is still in an alerting state.
2024-11-05 16:43:35.421 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling haard_eetkamer_procesbescherming_UIT with alertItem=haard_salon_procesbeschermingstimer, alertState=0 s, isAlerting=true, and initial alert false
2024-11-05 16:43:35.426 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Rule haard_eetkamer_procesbescherming_UIT has been called for haard_salon_procesbeschermingstimer
2024-11-05 16:43:35.428 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Waiting until null to send reminder for haard_salon_procesbeschermingstimer

As the code shown here shows, variable alertRuleUID is created based on the label of the triggering item. I’ll include some console.debug() instances there, and track some more…

LATER ADDITION

2024-11-05 21:37:13.765 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 0 s to 10 s
2024-11-05 21:37:13.766 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'haarden_procesbeschermingstimers' changed from 0 s to UNDEF through haard_salon_procesbeschermingstimer
2024-11-05 21:37:14.767 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 10 s to 9 s
2024-11-05 21:37:15.770 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 9 s to 8 s
2024-11-05 21:37:16.772 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 8 s to 7 s
2024-11-05 21:37:17.774 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 7 s to 6 s
2024-11-05 21:37:17.940 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 0 s to 10 s
2024-11-05 21:37:18.776 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 6 s to 5 s
2024-11-05 21:37:18.942 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 10 s to 9 s
2024-11-05 21:37:19.777 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 5 s to 4 s
2024-11-05 21:37:19.944 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 9 s to 8 s
2024-11-05 21:37:20.779 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 4 s to 3 s
2024-11-05 21:37:20.947 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 8 s to 7 s
2024-11-05 21:37:21.780 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 3 s to 2 s
2024-11-05 21:37:21.947 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 7 s to 6 s
2024-11-05 21:37:22.781 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 2 s to 1 s
2024-11-05 21:37:22.950 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 6 s to 5 s
2024-11-05 21:37:23.783 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_salon_procesbeschermingstimer' changed from 1 s to 0 s
2024-11-05 21:37:23.950 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 5 s to 4 s
2024-11-05 21:37:24.951 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 4 s to 3 s
2024-11-05 21:37:25.802 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'haard_eetkamer_procesbescherming' received command OFF
2024-11-05 21:37:25.803 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbescherming' changed from ON to OFF
2024-11-05 21:37:25.955 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 3 s to 2 s
2024-11-05 21:37:26.956 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 2 s to 1 s
2024-11-05 21:37:27.958 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'haard_eetkamer_procesbeschermingstimer' changed from 1 s to 0 s
2024-11-05 21:37:27.960 [INFO ] [hab.event.GroupItemStateChangedEvent] - Item 'haarden_procesbeschermingstimers' changed from UNDEF to 0 s through haard_eetkamer_procesbeschermingstimer
2024-11-05 21:37:29.983 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'haard_eetkamer_procesbescherming' received command OFF

We see haard_eetkamer_procesbescherming is being changed OFF too soon (at 21:37:25.802): this should have been haard_salon_procesbescherming.

2024-11-05 21:37:23.787 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 21:37:23.787 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_salon_procesbeschermingstimer and kamernaam = salon
2024-11-05 21:37:23.787 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_salon_procesbeschermingstimer and alertRuleUID = haard_salon_procesbescherming_UIT
2024-11-05 21:37:23.787 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_salon_procesbeschermingstimer and alertRuleUID = haard_salon_procesbescherming_UIT
2024-11-05 21:37:23.787 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing an Item event
2024-11-05 21:37:23.788 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 21:37:23.788 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 21:37:23.788 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 s from haard_salon_procesbeschermingstimer
2024-11-05 21:37:23.788 [DEBUG] [.haard_salon_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 21:37:23.789 [DEBUG] [.haard_salon_procesbeschermingstimer] - Converting threshold to value
2024-11-05 21:37:23.789 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 21:37:23.789 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing state  of type string
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is a string: 
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_salon_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 21:37:23.790 [DEBUG] [.haard_salon_procesbeschermingstimer] - Result is true
2024-11-05 21:37:23.791 [DEBUG] [.haard_salon_procesbeschermingstimer] - haard_salon_procesbeschermingstimer is in the alert state of 0 s
2024-11-05 21:37:23.793 [DEBUG] [.haard_salon_procesbeschermingstimer] - Calling the initial alert rule for haard_salon_procesbeschermingstimer
2024-11-05 21:37:23.797 [DEBUG] [.haard_salon_procesbeschermingstimer] - Creating looping alert timer for haard_salon_procesbeschermingstimer at 2024-11-05T21:37:25.791+01:00[SYSTEM]
2024-11-05 21:37:23.897 [DEBUG] [.haard_salon_procesbeschermingstimer] - Calling init alert rule for haard_salon_procesbeschermingstimer
2024-11-05 21:37:23.898 [DEBUG] [.haard_salon_procesbeschermingstimer] - No rule ID passed, ignoring
2024-11-05 21:37:23.955 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 21:37:23.955 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and kamernaam = eetkamer
2024-11-05 21:37:23.956 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and alertRuleUID = haard_eetkamer_procesbescherming_UIT
2024-11-05 21:37:23.956 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and alertRuleUID = haard_eetkamer_procesbescherming_UIT
2024-11-05 21:37:23.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing an Item event
2024-11-05 21:37:23.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 4 of type object
2024-11-05 21:37:23.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 4
2024-11-05 21:37:23.958 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 4 s from haard_eetkamer_procesbeschermingstimer
2024-11-05 21:37:23.958 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 21:37:23.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 21:37:23.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 21:37:23.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 21:37:23.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 21:37:23.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 21:37:23.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 21:37:23.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 21:37:23.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 21:37:23.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_eetkamer_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 21:37:23.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 4 s == 0 s
2024-11-05 21:37:23.964 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is false
2024-11-05 21:37:23.964 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_eetkamer_procesbeschermingstimer's new state is 4 s which is no longer in the alerting state, previously alerted = false
2024-11-05 21:37:23.964 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Exiting alerting state but alert was never sent, not sending an end alert for haard_eetkamer_procesbeschermingstimer
2024-11-05 21:37:24.956 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - Starting threshold alert
2024-11-05 21:37:24.956 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and kamernaam = eetkamer
2024-11-05 21:37:24.956 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and alertRuleUID = haard_eetkamer_procesbescherming_UIT
2024-11-05 21:37:24.957 [DEBUG] [ Alert.haarden-procesbescherming-UIT] - event.itemName = haard_eetkamer_procesbeschermingstimer and alertRuleUID = haard_eetkamer_procesbescherming_UIT
2024-11-05 21:37:24.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing an Item event
2024-11-05 21:37:24.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 3 of type object
2024-11-05 21:37:24.957 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 3
2024-11-05 21:37:24.958 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 3 s from haard_eetkamer_procesbeschermingstimer
2024-11-05 21:37:24.958 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 21:37:24.960 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 21:37:24.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 21:37:24.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 21:37:24.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 21:37:24.961 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 21:37:24.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 21:37:24.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 21:37:24.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 21:37:24.962 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_eetkamer_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 21:37:24.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 3 s == 0 s
2024-11-05 21:37:24.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is false
2024-11-05 21:37:24.963 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_eetkamer_procesbeschermingstimer's new state is 3 s which is no longer in the alerting state, previously alerted = false
2024-11-05 21:37:24.964 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Exiting alerting state but alert was never sent, not sending an end alert for haard_eetkamer_procesbeschermingstimer
2024-11-05 21:37:25.792 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 of type object
2024-11-05 21:37:25.793 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a QuantityType, converting to Quantity: 0
2024-11-05 21:37:25.793 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Populating record from Item metadata or rule defauls
2024-11-05 21:37:25.795 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting threshold to value
2024-11-05 21:37:25.796 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 21:37:25.796 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 21:37:25.796 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Converting hysteresis to value
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state  of type string
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is the empty string, no conversion possible
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Alert timer expired for haard_salon_procesbeschermingstimer with dnd between 00:00 and 00:00 and reminder period 
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Timeout  is not valid, using null
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 21:37:25.798 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - haard_salon_procesbeschermingstimer is still in an alerting state.
2024-11-05 21:37:25.798 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Calling haard_eetkamer_procesbescherming_UIT with alertItem=haard_salon_procesbeschermingstimer, alertState=0 s, isAlerting=true, and initial alert false
2024-11-05 21:37:25.799 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 3 s of type string
2024-11-05 21:37:25.799 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 3 s
2024-11-05 21:37:25.799 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 3 s
2024-11-05 21:37:25.799 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 3 s == 0 s
2024-11-05 21:37:25.799 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is false
2024-11-05 21:37:25.800 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing state 0 s of type string
2024-11-05 21:37:25.800 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a string: 0 s
2024-11-05 21:37:25.800 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - state is a Quantity: 0 s
2024-11-05 21:37:25.800 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Checking if we are in the alerting state: 0 s == 0 s
2024-11-05 21:37:25.800 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Result is true
2024-11-05 21:37:25.802 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Rule haard_eetkamer_procesbescherming_UIT has been called for haard_salon_procesbeschermingstimer
2024-11-05 21:37:25.805 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Waiting until null to send reminder for haard_salon_procesbeschermingstimer

At 21:37:23.797 a timer is installed for 21:37:25.791, under the umbrella of haard_salon_procesbeschermingstimer. However, around that time, stuff happens under the umbralla of haard_eetkamer_procesbeschermingstimer, including this strange entry, where both items are mixed up again:

2024-11-05 21:37:25.797 [DEBUG] [ard_eetkamer_procesbeschermingstimer] - Processing event for Item haard_salon_procesbeschermingstimer with properties: 
  Threshold          - 0 s
  Operator           - ==
  Invert             - false
  Reschedule         - false
  Alert Delay        - PT2S
  Reminder Period    - 
  Alert Rule ID      - haard_eetkamer_procesbescherming_UIT
  End Alert Rule ID  - 
  Init Alert Rule ID - 
  Gatekeeper Delay   - 0
  Hystersis          - 
  Rate Limt          - 
  DnD Start          - 00:00
  DnD End            - 00:00

…?

Ltty · November 6, 2024, 8:21am

Hi @rlkoshak,

got another exception for you. I have var dndStart = '20:00' and var dndEnd = '08:00' in my script. If there’s an alert during that period of time, I get the following exceptions:

2024-10-31 07:35:50.011 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID '43d0ae47f6' failed: org.graalvm.polyglot.PolyglotException: TypeError: invokeMember (reschedule) on org.openhab.core.automation.module.script.internal.action.TimerImpl@3cde137c failed due to: Cannot convert '08:00'(language: Java, type: java.lang.String) to Java type 'java.time.ZonedDateTime': Unsupported target type.

2024-10-31 07:35:50.011 [ERROR] [omation.script.javascript.43d0ae47f6] - Failed to execute script: TypeError: invokeMember (reschedule) on org.openhab.core.automation.module.script.internal.action.TimerImpl@3cde137c failed due to: Cannot convert '08:00'(language: Java, type: java.lang.String) to Java type 'java.time.ZonedDateTime': Unsupported target type.
        at <js>.notAlerting(<eval>:349)
        at <js>.procEvent(<eval>:538)
        at <js>.:program(<eval>:934)
        at org.graalvm.polyglot.Context.eval(Context.java:399)
        at com.oracle.truffle.js.scriptengine.GraalJSScriptEngine.eval(GraalJSScriptEngine.java:458)
        ... 23 more

Best,
Florian

rlkoshak · November 6, 2024, 3:57pm

What version are you running? In the latest version (the first line of code in the action should be // Version 1.2.

In the current version of the code the line that calles reschedule is 352, not 349.

I also don’t see how that error is possible in the current version. It’s complaining about scheduleTime which gets set by this line:

const scheduleTime =  generateAlertTime(time.toZDT(), record.dndStart, record.dndEnd);

The function is

var generateAlertTime = (timeout, dndStart, dndEnd) => {
  if(timeout === '' || (!(timeout instanceof time.ZonedDateTime) && !validateDuration(timeout))){
    console.debug('Timeout ' + timeout + ' is not valid, using null');
    return null;
  }

  let rval = time.toZDT(timeout.toString());
  let start = time.toZDT(dndStart);
  let end = time.toZDT(dndEnd);
  if(rval.isBetweenTimes(start, end)) {
    console.debug('Alert is scheduled during do not distrub time, moving to ' + dndEnd);
    rval = end;
    if(time.toZDT(rval).isBefore(time.toZDT())) {
      console.debug('Moving alert time to tomorrow');
      rval = timeUtils.toTomorrow(end);
    }
  }
  return rval;
}

The String “08:00” is converted to a time.toZDT() before it’s returned when you are between the DND times. But the error is saying that it’s still a String when reschedule is called.

If it continues after upgrading to the latest version of the code, something weird and subtle is going on.