Address timer drift issue

[bizprof]

Also introduced functions to convert between seconds and milliseconds to avoid repetitive code

[EasyG0ing1]

@bizprof

In the ResetAll.ino example, you have this line of code:

resetAllTimers(myReset.getStartTime());

I tried it both with and without the argument and it seems to work the same either way.

So I'm just curious as to why you passed the reset timers startTime into the method call? I like to keep things simple for people so any time I can make things easier to understand ... that's always one of the primary goals.

[bizprof]

Hi Mike, there is a slight difference between both variants. If you let it run without the extra parameter, the 30s timer will slowly drift away. See the attached log file for an Arduino UNO. This file has 2 sections, one with and one without the extra parameter. Without the parameter, timer drift is noticeable after only a couple 30s resets. Fine to drop it for the ResetAll example, if you feel it's too complicated. But the parameter itself should be kept in the resetAllTimers code, as an undocumented feature perhaps.

ResetAll log.txt

[EasyG0ing1]

@bizprof Well, I'm ok to leave it in, I'm just going to write a comment in the code explaining why it's there. Which, ultimately, will help people prevent the drift.

[bizprof]

Great! You raise an important point, though: I haven't commented my PRs enough. When revisiting my own code even a day later, I can't always make sense of what I wrote. So, here's my mid-year resolution to include more comments in the future! Totally agree with you in regards to keeping the code simple for the benefit of others. At least as far as the examples go!

[EasyG0ing1]

@bizprof

Michael,

I looked at the results in the logs you collected and brought them into excel and I couldn't really see what you are talking about. So I modified your example code so that it specifically records the times between each firing of the 30 second timer, then I ran the code with and without the myReset.getStartTime() argument, and I don't see any time drift at all. I'm running this on a nano which should be identical to an UNO.

Here is the sketch I used and the results are in the attached file (ignore the first recording in the log the lastTime variable needed to survive one log cycle before things were on track) ... am I doing something wrong or am I calculating things improperly so that I'm not seeing the drift?

#include <BlockNot.h>

BlockNot timer1( 1, SECONDS);
BlockNot timer2( 5, SECONDS);
BlockNot timer3( 7500 );

BlockNot myReset   (30, SECONDS);  // Timer to trigger reset of all timers every 30s

unsigned long startTime;   // To count seconds independent of timers
unsigned long thisTime;
unsigned long lastTime;

void printTimers() {
    String heading = "Timer\tDuration\tUnits\n-----------------------------";
    String t1 = "One\t" + String(timer1.DURATION) + "\t\t" + timer1.GET_UNITS;
    String t2 = "Two\t" + String(timer2.DURATION) + "\t\t" + timer2.GET_UNITS;
    String t3 = "Three\t" + String(timer3.DURATION) + "\t\t" + timer3.GET_UNITS;
    Serial.println(heading);
    Serial.println(t1);
    Serial.println(t2);
    Serial.println(t3);
    Serial.print("\n");
    Serial.println(F("Now,Last,Delta"));
}

unsigned long getTime() {
  return millis() - startTime;
}

void printReset(unsigned long printTime) {
    String pNow = String(printTime);
    String pLast = String(lastTime);
    unsigned long delta = thisTime - lastTime;
    String pDelta = String(delta);
    Serial.println(pNow + "," + pLast +"," + pDelta);
    lastTime = thisTime;
}

void setup() {
    Serial.begin(115200);
    delay(1500);
    Serial.println(F("READY!\n"));
    delay(1000);
    printTimers();
    startTime = millis();
    resetAllTimers(startTime);
    lastTime = startTime;
}

void loop()
{
    timer1.TRIGGERED;
    timer2.TRIGGERED;
    timer3.TRIGGERED;
    if (myReset.TRIGGERED) {
        thisTime = getTime();
        resetAllTimers(myReset.getStartTime());
        printReset(thisTime);
    }
}

ResetAll_log.txt

[bizprof]

Hi Mike, did some more testing. As long as the loop() takes less than 1ms, all is fine, and the results will be the same. The moment you introduce a bit more load, the drift accours. Try adding a delay(10); (which you had in your example script before), and you should see a drift after the first couple resetAllTimers() cycles. In my environment with 10ms delay:

Now,Last,Delta 30007,2505,27502 60013,30007,30006 90019,60013,30006 120026,90019,30007 150033,120026,30007

With 3ms delay:

Now,Last,Delta 30000,2505,27495 60000,30000,30000 90001,60000,30001 120001,90001,30000 150001,120001,30000 180002,150001,30001 210002,180002,30000 240002,210002,30000 270002,240002,30000 300004,270002,30002 330004,300004,30000 360005,330004,30001 390005,360005,30000 420005,390005,30000

Most importantly, once a drift occurs, it will never recover from that. Some board-internal processes (such as garbage collection or heap reallocation) will take time as well, at random intervals. I noticed that Serial.println with lots of strings and "+" in between seem to be especially bad for memory management.

[EasyG0ing1]

@bizprof

Well, what I think is important to note ... even in the data that you just posted, is that when it takes another millisecond in between timer cycles, at least subsequent cycles are spot on at 30 seconds... the drift doesn't seem to be cumulative in terms of the timer duration itself ... it never changes... but the anomalous times that you're seeing are due to factors outside of our control - at least in the context of the timer library.

There really is only one way to get a mark at the exact same interval every time ... and that's with a multi-core processor and a second process running in another thread that does nothing but keeps time for the main thread. Because in a single-core CPU like the Nano or the Uno, I don't see how it's possible to prevent slight variations like this.

OR, use an RTC chip with an interrupt timer. The teensy 4.0 has one built-in.

[bizprof]

All looks good so far, thanks Mike! Well, it's been a very productive day indeed! Have a great weekend! Michael :-)