espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.28k stars 7.35k forks source link

Hardware timer issues #10064

Closed khorner116 closed 1 month ago

khorner116 commented 1 month ago

Board

Adafruit ESP32 Feather

Device Description

Standard board from Adafruit chip is ESP32-D0WD-V3 (revision v3.0)

Hardware Configuration

No

Version

latest master (checkout manually)

IDE Name

Adrduino IDE2.3.2

Operating System

Win 11

Flash frequency

80mhz

PSRAM enabled

yes

Upload speed

921600

Description

Board runs great. I just can't figure out why the timers are so far off. I have a watch dog timer in test (using the example code) that should trip in 7.5 secs. It actually trips at 7.982 secs. The test setup is very clean. Nothing else going on other than set the watch dog and loop in a while stmt till it trips. then the WD reset prints out the elapsed millis.

I have another time running at 10 hz... actually comes in at 10.5 hz.

Why the error? I understand RTOS overhead, but that much? Should I not use 1 mhz base clock rates?

Sketch

// Set Watch Dog timer as described here
  //.......  https://github.com/espressif/arduino-esp32/blob/master/libraries/ESP32/examples/Timer/WatchdogTimer/WatchdogTimer.ino
  if (DisplayOnConsole)Serial.println(F("\nSetting up WD Timer"));
  WDtimer = timerBegin(1000000);                   //timer  run at 1MHZ
  timerAttachInterrupt(WDtimer, &resetModule);                     //attach the interrupt service routine
  timerAlarm(WDtimer, wdtTimeout*1000, false,0);    //set time in usecs; we're doing a 5 sec watchdog timeout
  delay(1);                                           // Reset the time with periodic calls timerWrite(timer1,0) 
  ResetWDtimer();

    debugtime=millis();
  while(1){
    delay(10);
    debugtime=millis()-debugtime;
  }

Debug Message

>>Text message switch is On
14:55:47.598 -> Setting up WD Timer
14:55:55.098 -> 
14:55:55.098 -> 
14:55:55.098 -> WatchDog reset
14:55:55.098 -> ......elapsed time: 7982 
14:55:55.098 -> 
14:55:55.098 -> 
14:55:55.098 -> ets Jul 29 2019 12:21:46

Other Steps to Reproduce

no

I have checked existing issues, online documentation and the Troubleshooting Guide

VojtechBartoska commented 1 month ago

@P-R-O-C-H-Y Please help with triage, thanks

khorner116 commented 1 month ago

Sure, how can I help? Questions?

P-R-O-C-H-Y commented 1 month ago

Sure, how can I help? Questions?

I am currently testing and investigating the alarms. I will let you know when I have any news or questions. Thanks you for asking @khorner116 :)

P-R-O-C-H-Y commented 1 month ago

@khorner116 I have tested the Timers and when I set 7500 ms alarm, its triggered exactly at 7500 ms. Can you update your sketch to match the elapsed time calculation from this sketch? You can capture the time in the ISR of the alarm.

const int wdtTimeout = 7500;  //time in ms to trigger the watchdog
hw_timer_t *timer = NULL;

long starttime = 0;
long reboottime = 0;
bool reboot = false;

void ARDUINO_ISR_ATTR resetModule() {
  //esp_restart();
  reboottime = millis();
  reboot = true;
}

void setup() {
  Serial.begin(115200);

  timer = timerBegin(1000000);                     //timer 1Mhz resolution
  Serial.println("Timer frequency:");
  Serial.println(timerGetFrequency(timer));
  timerAttachInterrupt(timer, &resetModule);       //attach callback
  timerAlarm(timer, wdtTimeout * 1000, true, 0);  //set time in us
}

void loop() {
  timerWrite(timer, 0);  //reset timer (feed watchdog)
  starttime=millis();
  while (!reboot) {
    delay(5);
  }
  reboot = false;
  reboottime = reboottime - starttime;

  Serial.print("Reboot time is = ");
  Serial.println(reboottime);  //should be under 3000
}

If you still have the issues, can you please post reproducible sketch? Thanks

khorner116 commented 1 month ago

PROCHY Thanks for your help. I loaded your code, and it ran fine. Tripped exactly on 7.5 secs. I added the second timer.... I get the slightly off results I saw before, but not as bad. The 7.5 sec shifts to 7.499, 7.496, 7.509. Which is just fine for a WD timer. The 5 sec. interval driven by a 10 hz pulse goes to 4.975, 5.0011, 5.030, 5.017. -- a 0.5% error. In my system, I'm seeing bigger errors than that, but I have other things going on. It seems the timers are affected by activity. Is this an RTOS issue? Looks like something I may have to live with.

Also, in the docs it said I don't need to specify a particular one of the 4 hardware timers, they are allocated from a pool. Maybe I am declaring the second one incorrectly, but it does seem to almost work.

Here's my example code. Results follow.

include

include "esp_system.h"

include "rom/ets_sys.h"

const int wdtTimeout = 7500; //time in ms to trigger the watchdog hw_timer_t timer = NULL; hw_timer_t timer2 = NULL;

long starttime = 0; long reboottime = 0; bool reboot = false; int counter =0; bool counter2trip = false;

void ARDUINO_ISR_ATTR resetModule() { //esp_restart(); reboottime = millis(); reboot = true; }

void ARDUINO_ISR_ATTR Timer2Module() { counter++; if(counter>100){counter=0; counter2trip=true;} }

void setup() { Serial.begin(115200); delay(2000); timer = timerBegin(1000000); //timer 1Mhz resolution Serial.println("Timer frequency:"); Serial.println(timerGetFrequency(timer)); timerAttachInterrupt(timer, &resetModule); //attach callback timerAlarm(timer, wdtTimeout * 1000, true, 0); //set time in us

timer2 = timerBegin(1000000); //timer 1Mhz resolution timerAttachInterrupt(timer2, &Timer2Module); //attach callback timerAlarm(timer2, 100000, true, 0); //set time in us 10Hz

}

void loop() { timerWrite(timer, 0); //reset timer (feed watchdog) starttime=millis(); while (!reboot) { delay(5); if(counter2trip){ Serial.println(">>>>counter2 tick"); counter2trip=false;} } reboot = false; reboottime = reboottime - starttime;

Serial.print("Reboot time is = "); Serial.println(reboottime); //should be under 3000 }

Results... 21:46:57.897 -> Reboot time is = 7500 21:47:00.421 -> >>>>counter2 tick 21:47:05.396 -> >>>>counter2 tick 21:47:05.439 -> Reboot time is = 7500 21:47:10.397 -> >>>>counter2 tick 21:47:12.935 -> Reboot time is = 7500 21:47:15.427 -> >>>>counter2 tick 21:47:20.444 -> >>>>counter2 tick 21:47:20.444 -> Reboot time is = 7500 21:47:25.432 -> >>>>counter2 tick 21:47:27.916 -> Reboot time is = 7500 21:47:30.415 -> >>>>counter2 tick 21:47:35.422 -> >>>>counter2 tick 21:47:35.422 -> Reboot time is = 7500

P-R-O-C-H-Y commented 1 month ago

@khorner116 Am I missing something, as 10 Hz interval is 0,1 ms -> counting to 100 is 0,1*100 = 10s. How are you getting 5 seconds?? Also a note, the times you are checking are calculated as the reboot time? Or you are checking it by the timestamp in the print?

P-R-O-C-H-Y commented 1 month ago

I did slightly edit your posted sketch to get 5s of the 2nd timer:

#include <Arduino.h>
#include "esp_system.h"
#include "rom/ets_sys.h"

const int wdtTimeout = 7500; //time in ms to trigger the watchdog
hw_timer_t *timer = NULL;
hw_timer_t *timer2 = NULL;

long starttime = 0;
long reboottime = 0;
bool reboot = false;
int counter =0;
bool counter2trip = false;
long timer2time = 0;
long timer2start = 0;

void ARDUINO_ISR_ATTR resetModule() {
//esp_restart();
reboottime = millis();
reboot = true;
}

void ARDUINO_ISR_ATTR Timer2Module() {
counter++;
if(counter>=50){counter=0; counter2trip=true; timer2time = millis();}
}

void setup() {
Serial.begin(115200);
delay(2000);
timer = timerBegin(1000000); //timer 1Mhz resolution
Serial.println("Timer frequency:");
Serial.println(timerGetFrequency(timer));
timerAttachInterrupt(timer, &resetModule); //attach callback
timerAlarm(timer, wdtTimeout * 1000, true, 0); //set time in us

timer2 = timerBegin(1000000); //timer 1Mhz resolution
timerAttachInterrupt(timer2, &Timer2Module); //attach callback
timerAlarm(timer2, 100000, true, 0); //set time in us 10Hz
timerWrite(timer2, 0);
timer2start = millis();

}

void loop() {
timerWrite(timer, 0); //reset timer (feed watchdog)
starttime=millis();
while (!reboot) {
  delay(5);
  if(counter2trip) { 
    Serial.println(">>>>counter2 tick"); 
    Serial.printf("Timer2 trigger time = %d\n", timer2time - timer2start);
    timer2time = 0; 
    timer2start = millis();
    counter2trip=false;

  }
}
reboot = false;
reboottime = reboottime - starttime;

Serial.print("Reboot time is = ");
Serial.println(reboottime); 
}

This is the log now:

14:26:00.543 -> >>>>counter2 tick
14:26:00.543 -> Timer2 trigger time = 5000
14:26:03.138 -> Reboot time is = 7500
14:26:05.558 -> >>>>counter2 tick
14:26:05.558 -> Timer2 trigger time = 5000
14:26:10.546 -> >>>>counter2 tick
14:26:10.546 -> Timer2 trigger time = 5000
14:26:10.660 -> Reboot time is = 7500

As you can see in the timestamp, it's now exactly 5000 ms, but if you calculate the time it's correct. The Serial prints takes some time. So your timers should be fine. I don't know what your system is doing and how complicated is your main application, but Timers are working correctly. You are just delayed in the processing.

khorner116 commented 1 month ago

great. thanks for the help. I was most worried that I had an issue with the timers interfering with each other.

thanks again.

k

On Fri, Jul 26, 2024 at 8:31 AM Jan Procházka @.***> wrote:

I did slightly edit your posted sketch to get 5s of the 2nd timer:

include

include "esp_system.h"

include "rom/ets_sys.h"

const int wdtTimeout = 7500; //time in ms to trigger the watchdog hw_timer_t timer = NULL; hw_timer_t timer2 = NULL;

long starttime = 0; long reboottime = 0; bool reboot = false; int counter =0; bool counter2trip = false; long timer2time = 0; long timer2start = 0;

void ARDUINO_ISR_ATTR resetModule() { //esp_restart(); reboottime = millis(); reboot = true; }

void ARDUINO_ISR_ATTR Timer2Module() { counter++; if(counter>=50){counter=0; counter2trip=true; timer2time = millis();} }

void setup() { Serial.begin(115200); delay(2000); timer = timerBegin(1000000); //timer 1Mhz resolution Serial.println("Timer frequency:"); Serial.println(timerGetFrequency(timer)); timerAttachInterrupt(timer, &resetModule); //attach callback timerAlarm(timer, wdtTimeout * 1000, true, 0); //set time in us

timer2 = timerBegin(1000000); //timer 1Mhz resolution timerAttachInterrupt(timer2, &Timer2Module); //attach callback timerAlarm(timer2, 100000, true, 0); //set time in us 10Hz timerWrite(timer2, 0); timer2start = millis();

}

void loop() { timerWrite(timer, 0); //reset timer (feed watchdog) starttime=millis(); while (!reboot) { delay(5); if(counter2trip) { Serial.println(">>>>counter2 tick"); Serial.printf("Timer2 trigger time = %d\n", timer2time - timer2start); timer2time = 0; timer2start = millis(); counter2trip=false;

} } reboot = false; reboottime = reboottime - starttime;

Serial.print("Reboot time is = "); Serial.println(reboottime); }

This is the log now:

14:26:00.543 -> >>>>counter2 tick 14:26:00.543 -> Timer2 trigger time = 5000 14:26:03.138 -> Reboot time is = 7500 14:26:05.558 -> >>>>counter2 tick 14:26:05.558 -> Timer2 trigger time = 5000 14:26:10.546 -> >>>>counter2 tick 14:26:10.546 -> Timer2 trigger time = 5000 14:26:10.660 -> Reboot time is = 7500

As you can see in the timestamp, it's now exactly 5000 ms, but if you calculate the time it's correct. The Serial prints takes some time. So your timers should be fine. I don't know what your system is doing and how complicated is your main application, but Timers are working correctly. You are just delayed in the processing.

— Reply to this email directly, view it on GitHub https://github.com/espressif/arduino-esp32/issues/10064#issuecomment-2252665782, or unsubscribe https://github.com/notifications/unsubscribe-auth/AICQSLNPNHUWMBLVJONJOS3ZOI6TLAVCNFSM6AAAAABLJEXQPKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENJSGY3DKNZYGI . You are receiving this because you were mentioned.Message ID: @.***>

P-R-O-C-H-Y commented 1 month ago

@khorner116 Thank you for feedback. I am closing the issue as solved. Feel free to reopen/comment or create a new issue if you occur any problems :)