[BUG] Schedule not turning on, revisited

[CodeSlinger69]

nodejs-poolController Version/commit

head

nodejs-poolController-dashPanel Version/commit

No response

relayEquipmentManager Version/commit

No response

Node Version

No response

Platform

No response

RS485 Adapter

No response

Are you using Docker?

• [ ] Yes.

OCP

No response

Pump(s)

No response

Chlorinator(s)

No response

What steps will reproduce the bug?

My apologies for bringing this up again, but I've found another schedule issue. I've simplified the configuration to the bare minimum (see attached poolConfig.json), and provide steps to reproduce.

poolConfig.json.txt

Steps to reproduce:

1. Set clock to 23:59:00. Start njsPC. Schedule 2 will turn on as expected.
2. Wait for clock to roll past midnight. Schedule 2 will turn off as expected, schedule 1 will turn on as expected.
3. Set clock to 16:00. Schedule 1 will turn off, as expected.
4. Set clock to 18:01:00. Schedule 2 does NOT turn on, resulting in image shown below.

What happens?

What should have happened?

Schedule 2 should be on.

Additional information

I tried to trace the logic and debug this myself, but I'll be honest, the logic is not intuitive to me. It looks however like there is some caching as to whether a given schedule/circuit was previously on during a given day. Perhaps that caching needs to be reset once that schedule/circuit is legitimately off?

[rstrouse]

Click the pool button. The schedule will come back on and turn off at 00:00:59. Schedules must be overridable. This means that while a schedule is interrupted you should be able to turn it off and it should resume when you resume the state. Imagine how annoying that would be if you turned off your cleaner then pulled it from the pool and suddenly it kicked it back on again.

In fact there is a manual override function in the options that will show you when you have performed such a function.

[CodeSlinger69]

Thanks for that explanation. I do understand that the pool button can be clicked to start the circuit manually, or indeed shut it off manually if needed.

However, what I am describing in this report should be only related to enabling a circuit automatically when scheduled. The exact steps described do not rely on any manual turning on or off. I only move the clock forward (using the underlying operating system's tools) to accelerate the testing. If you let the schedule run in actual time (i.e. don't change the clock), the exact same thing will happen, it will just take you 18 hours to see it.

Maybe I'm misunderstanding how schedules work. I think I've been doing it all wrong since I moved to Nixie, to be honest. But my understanding would be that when a schedule is due to turn on a circuit, that circuit turns on, even if a different schedule turned it off 3 hours prior. In the image above, you can see that didn't happen. And I'll reiterate - no manual intervention was involved.

[rstrouse]

If you let the schedule run in actual time (i.e. don't change the clock), the exact same thing will happen, it will just take you 18 hours to see it.

I do not believe that is true since a new frame will be calculated as soon as it rolls over to the next day. You have forced it to roll over to the next day then rolled it back a day.

Look in poolState.json you will see the calculated schedule timeframe.

     ...
      "startTime": 1080,
      "endTime": 1440,
      "isActive": true,
      "disabled": false,
      "manualPriorityActive": false,
      "isOn": false,
      "triggered": false,
      "scheduleTime": {
        "calculated": true,
        "shouldBeOn": false,
        "calculatedDate": "2023-07-24T00:00:00.000-0700",
        "startTime": "2023-07-24T18:00:00.000-0700",
        "endTime": "2023-07-25T00:00:59.999-0700"
      },
      ...

[CodeSlinger69]

You have forced it to roll over to the next day then rolled it back a day.

I tried to be as precise as possible in the 4 steps to reproduce. In none of those steps do I roll back the clock. What I do however, is suggest to move the clock forward to skip boring time that would otherwise just be waiting.

I have however, tested the problem by actually waiting the 18 hours in real time. I did this three times, and is repeatable.

Let me work up a simpler scenario, however. I believe the same thing will happen if the schedule durations are 5 minutes or 15 hours, and shorter durations will make it easier to test. I'll also monitor poolState.json and see what I can see.

[rstrouse]

Bottom line is that when it recalculates it resets the triggered flag and calculates the schedule for the next run time as of the current date. When you rolled over into 07/25 the next run time for triggering will be based upon that rollover. When the schedule runs its course where the triggered flag is true and the end time is less than the current time, it will again go through and grab the next run time from the current time. Bear in mind it will only ever trigger a schedule if it has not already done so.

The triggered flag is cleared under two conditions.

1. The clock rolls over into the next day.
2. The current end time expires.

I have set up another scenario to include the 2400 time (which is actually 00:00:59.999 on the following day).

[CodeSlinger69]

Ok, here's a set of steps that can reproduce this in 10 minutes, using a modified schedule as in the poolConfig.json pasted below. I understand that the schedule is unrealistic, its just to test the scenario.

1. rm poolState.json, set clock to 23:57, start njsPC.
2. Wait until 00:05
3. Note that schedule 2 does not turn on at 00:05 or later.

I set my clock to July 26, 23:57 to start this test. Date doesn't matter as these two schedules run every day of the week. I monitored poolState.json during this test and took snapshots at the important points. I think I might have an idea of what's happening, if its not too forward of me to say so. I'm thinking that when a schedule turns off, the next start/end date/time needs to be recalculated; when schedule 2 turns off in this scenario, it is being recalculated but in error (according to my eyes, and my understanding of how I think this should work).

At 23:57, we startup njsPC, and all looks good, schedule 2 is on:

// schedule 1
      "scheduleTime": {
        "calculatedDate": "2023-07-26T00:00:00.000-0700",
        "startTime": "2023-07-27T00:00:00.000-0700",
        "endTime": "2023-07-27T00:03:59.999-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false
// schedule 2
      "scheduleTime": {
        "calculatedDate": "2023-07-26T00:00:00.000-0700",
        "startTime": "2023-07-26T00:05:00.000-0700",
        "endTime": "2023-07-27T00:00:59.999-0700",
        "calculated": true,
        "shouldBeOn": true
      },
      "isOn": true,

At 00:01, schedule 2 has turned off and the date has changed (it's now July 27th). The next calculated start time and end time has two problems. Start time has yesterday's date, and end time has yesterday's date and the wrong end time (should be 00:00:59.999, the same as in the 23:57 snapshot).

// schedule 1
      "scheduleTime": {
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-27T00:00:00.000-0700",
        "endTime": "2023-07-27T00:03:59.999-0700",
        "calculated": true,
        "shouldBeOn": true
      },
      "isOn": true,
// schedule 2
      "scheduleTime": {
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-26T00:05:00.000-0700",
        "endTime": "2023-07-26T00:05:00.000-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false,

At 00:04, neither schedule "shouldBeOn", as expected, but start/end for schedule 2 is still wrong.

// schedule 1
      "scheduleTime": {
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-27T00:00:00.000-0700",
        "endTime": "2023-07-27T00:03:59.999-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false,
// schedule 2
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-26T00:05:00.000-0700",
        "endTime": "2023-07-26T00:05:00.000-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false,

At 00:05, schedule 2 is not on (it should be), due to start/end dates still being set to yesterday, and the end time being set the same as the start time.

// schedule 1
      "scheduleTime": {
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-27T00:00:00.000-0700",
        "endTime": "2023-07-27T00:03:59.999-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false,
// schedule 2
      "scheduleTime": {
        "calculatedDate": "2023-07-27T00:00:00.000-0700",
        "startTime": "2023-07-26T00:05:00.000-0700",
        "endTime": "2023-07-26T00:05:00.000-0700",
        "calculated": true,
        "shouldBeOn": false
      },
      "isOn": false,

As a next step, I'll see if I can debug this and identify where in the code the call to recalculate the next start/end for a schedule happens. But as I mentioned, this logic is difficult for me to follow, but I'll try.

poolConfig.json.txt

[CodeSlinger69]

Bottom line is that when it recalculates it resets the triggered flag and calculates the schedule for the next run time as of the current date. When you rolled over into 07/25 the next run time for triggering will be based upon that rollover. When the schedule runs its course where the triggered flag is true and the end time is less than the current time, it will again go through and grab the next run time from the current time. Bear in mind it will only ever trigger a schedule if it has not already done so.

The triggered flag is cleared under two conditions.

1. The clock rolls over into the next day.
2. The current end time expires.

I have set up another scenario to include the 2400 time (which is actually 00:00:59.999 on the following day).

Ack, sorry. I didn't reload the page before I posted my very long comment just above.

In reading what you just wrote, I changed the end time for schedule 2 to 23:59 instead of 24:00, and everything worked fine. I think I'm just going to avoid 00:00 and 24:00 in my schedules and save both of us some grief.

Did I mention that I have a very long hatred of edge cases? Always a PITA to anticipate and code for those.

[CodeSlinger69]

Working now, thanks @rstrouse. Closing this issue.