Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Excessive time delay encountered when reading #12

Closed
brownrb opened this issue Nov 30, 2021 · 10 comments
Closed

Excessive time delay encountered when reading #12

brownrb opened this issue Nov 30, 2021 · 10 comments

Comments

@brownrb
Copy link

brownrb commented Nov 30, 2021

Hi
Thank you for writing the library. I am trying to integrate the library into my own project.
But I have found, for me, a very significant issue, and would seek direction on how this might be overcome.
I started to use the esp32time library, and I can get the date/time and can set the date/time.

here is my code. I have a valid struct tm which I pass to this function, which writes to the esp32rtc and one that reads from the esp32rtc

void set_rtc_date_time_esp32(struct tm *newtime)
{
Serial.println("setESP32rtc: start");
esp32rtc.setTimeStruct(rtc_loc);
Serial.println("setESP32rtc: end");
}

void get_rtc_date_time_esp32()
{
Serial.println("get_rtc_date_time_esp32: start");
rtc_loc = esp32rtc.getTimeStruct();
Serial.println("get_rtc_date_time_esp32: end");
}

here is the serial out statements from the Arduino monitor window. As you can see from the time stamps, 5 seconds is being consumed most of the time by esp32rtc.getTimeStruct();
That is really problematic for me because I need to service multiple requests in a timely fashion, and not being able to run any other code whilst waiting for getTimeStruct(); to finish is a deal-breaker.

Is there a way to make this faster without such a huge time consumer?
Cheers
Robert

23:28:48.609 -> get_rtc_date_time_esp32: start
23:28:53.610 -> get_rtc_date_time_esp32: end

23:28:53.610 -> get_rtc_date_time_esp32: start
23:28:58.596 -> get_rtc_date_time_esp32: end

23:29:54.506 -> get_rtc_date_time_esp32: start
23:29:59.508 -> get_rtc_date_time_esp32: end

23:30:12.057 -> setESP32rtc: start
23:30:12.057 -> setESP32rtc: end

23:30:12.057 -> get_rtc_date_time_esp32: start
23:30:12.057 -> get_rtc_date_time_esp32: end

23:30:35.679 -> setESP32rtc: start
23:30:35.679 -> setESP32rtc: end

@GodayMax
Copy link

GodayMax commented Dec 4, 2021

same issue

@Chagui-
Copy link

Chagui- commented Dec 13, 2021

Happens to me if y set the year below 2017. If i set the year to something above that, say 2019, then it works mysteriously.
Also if y set the time for example at year 2050, it also doesn't work.

  // time tests
  log_d("setting to 2010");
  rtc.setTime(0, 0, 0, 1, 1, 2010);
  for (int i = 0; i < 5; ++i){
    log_d("End Getting time: %s.", rtc.getTime("%Y-%m-%dT%H:%M:%S").c_str()); //this takes too long
  }
  log_d("setting to 2021");
  rtc.setTime(0, 0, 0, 1, 1, 2021);
  for (int i = 0; i < 5; ++i){
    log_d("End Getting time: %s.", rtc.getTime("%Y-%m-%dT%H:%M:%S").c_str()); //this works correctly
  }
  log_d("setting to 2010");
  rtc.setTime(0, 0, 0, 1, 1, 2010);
  for (int i = 0; i < 5; ++i){
    log_d("End Getting time: %s.", rtc.getTime("%Y-%m-%dT%H:%M:%S").c_str()); //this takes too long again
  }
  // end time tests

@Chagui-
Copy link

Chagui- commented Dec 13, 2021

Found the actual reason:.
In esp32-hal-time.c

bool getLocalTime(struct tm * info, uint32_t ms)
{
    uint32_t start = millis();
    time_t now;
    while((millis()-start) <= ms) {
        time(&now);
        localtime_r(&now, info);
        if(info->tm_year > (2016 - 1900)){
            return true;
        }
        delay(10);
    }
    return false;
}

It's actually programed that if the year es 2016 or less, then it remains in the loop (which runs for 5 sec by default).
When you set the time above 2042 then it goes back to 0 and gets stuck in the loop again.

@brownrb
Copy link
Author

brownrb commented Dec 14, 2021

I am not sure you read my comment correctly. I am using the call
esp32rtc.getTimeStruct();
which returns a struct filled in, and stated that was my issue.

The call does not accept any arguments or parameters in the call. So for me there is nothing to set as the call is meant to do the setting not me.

The call getLocalTime is not an issue here.

The 5s is lost in the esp32rtc.getTimeStruct() call. Does this make it clearer?

void get_rtc_date_time_esp32()
{
Serial.println("get_rtc_date_time_esp32: start");
rtc_loc = esp32rtc.getTimeStruct();
Serial.println("get_rtc_date_time_esp32: end");
}

23:28:48.609 -> get_rtc_date_time_esp32: start
23:28:53.610 -> get_rtc_date_time_esp32: end

@GodayMax
Copy link

Found the actual reason:. In esp32-hal-time.c

bool getLocalTime(struct tm * info, uint32_t ms)
{
    uint32_t start = millis();
    time_t now;
    while((millis()-start) <= ms) {
        time(&now);
        localtime_r(&now, info);
        if(info->tm_year > (2016 - 1900)){
            return true;
        }
        delay(10);
    }
    return false;
}

It's actually programed that if the year es 2016 or less, then it remains in the loop (which runs for 5 sec by default). When you set the time above 2042 then it goes back to 0 and gets stuck in the loop again.

It is wired why they wrote this loop, this section seems done nothing

@Chagui-
Copy link

Chagui- commented Dec 14, 2021

The call getLocalTime is not an issue here.

The 5s is lost in the esp32rtc.getTimeStruct() call.

Yes, the actual time sink is in getLocalTime(struct tm * info, uint32_t ms), which is being called inside esp32rtc.getTimeStruct(), and also in esp32rtc.getTime(), as seen in the following code.

// ESP32Time.cpp
/*!
    @brief  get the internal RTC time as a tm struct
*/
tm ESP32Time::getTimeStruct(){
  struct tm timeinfo;
  getLocalTime(&timeinfo); // the 5 seconds are wasted here!
  return timeinfo;
}
/*!
    @brief  get the time as an Arduino String object
*/
String ESP32Time::getTime(){
	struct tm timeinfo = getTimeStruct();
	char s[51];
	strftime(s, 50, "%H:%M:%S", &timeinfo);
	return String(s);
}

What if we include the timeout argument in the call so it passes it down to getLocalTime? this way we can control the 5 seconds with the library. And by default we could make it 5 seconds too.

Proposal:

// ESP32Time.cpp
/*!
    @brief  get the internal RTC time as a tm struct
*/
tm ESP32Time::getTimeStruct(uint32_t timeout_millis = 5000){
  struct tm timeinfo;
  getLocalTime(&timeinfo, timeout_millis);
  return timeinfo;
}
/*!
    @brief  get the time as an Arduino String object
*/
String ESP32Time::getTime(uint32_t timeout_millis = 5000){
	struct tm timeinfo = getTimeStruct(timeout_millis);
	char s[51];
	strftime(s, 50, "%H:%M:%S", &timeinfo);
	return String(s);
}

@brownrb
Copy link
Author

brownrb commented Dec 16, 2021

Time delays in anything should be at least be reasonable.
the issue I have is that this call is 5s long. Why is that? You seem to indicate that the code is wrong.
So why cannot the code for those calls be fixed, instead of asking every library user to rewrite their code.

It does not solve the issue to pass a time value to the call.
At present it takes 5s to time out. Why cannnot the code be rewritten so it doesnt timeout.
Are we not better to solve this at the source instead of trying to use a workaround for everyone using the library?
That does not sound like common-sense or even logical.

It would be like having to blow air into the tyres of your vechile every time you use the car, because the manufacturer made tyres that leaked air..

Is the original author around or have they abandoned this code? I see it has not been updated for a while. Does anyone know if there another library available which does not have these issues?

What I see is this
The user calls gettimestruct, which creates a struct tm timeinfo.
The fields are not initialized.
It then calls getlocaltime and passes a pointer to timeinfo
In getlocaltime it creates
time(&now);
and then uses that to fill-in the timeinfo fields.

And looking at the code, I think it would have been much better for users to pass a truct tm * to getTimeStruct() rather than getTimeStruct() returning
a pointer to one that it created. It could also have returned a bool value meaning success or fail.

bool getTimeStruct(struct tm * info);

so my code would have been
success = getTimeStruct(&mytime);

My 2c worth

@fbiego
Copy link
Owner

fbiego commented Dec 20, 2021

maybe I should implement a getLocalTime function in the library without the loop and delay

@brownrb
Copy link
Author

brownrb commented Dec 21, 2021

I really do think that getTimeStruct() needs to change
To have a function one calls to allocate its own memory, then return a pointer to that memory, I think that really is not a good thing to do. As I outlined above, being passed a reference to a struct of type tm is a better way to do that.

Let me explain - each time that getTimeStruct is called, it allocates a block of memory and returns a pointer to it.

Now it might be that I have a need to re-init the NTP side (lost connection, timeout etc), well, everytime I do that a new block of memory is allocated by getTimeStruct

And if my app was running 24/7 and experienced say 5 errors in ntp per day, well over 1 week that is 35 memory blocks allocated by gettimestruct

If gettimestruct was rewritten and passed a reference, then
my code creates a struct tm and passes its pointer to gettimestruct, which fills in the fields.
You can now see that after 1 week I only every created 1 time struct.

This issue I raised about the 5s wait that esp chips can't avoid when calling the library, that is really bad. It is bad because we have to wait and cannot do other things till its done.

There is just so much going on in esp32 chips it makes a mockery of responsiveness - for example, say I also have a web browesr running, espnow, mqtt, mdns etc - do you realise that waiting 5s for the library to time out just places a significant response delay in servicing requests for webserver, mqtt etc. The code just has no choice but to sit and wait, and that reaally is not a good way to do things.

Are you the original developer of the library?

@brownrb brownrb closed this as completed Dec 21, 2021
@brownrb brownrb reopened this Dec 21, 2021
@brownrb
Copy link
Author

brownrb commented Dec 21, 2021

Sorry I did not mean to close the issue

fbiego added a commit that referenced this issue Jul 29, 2022
Temporary fix 2K38 bug #10
#12
@fbiego fbiego closed this as completed Jul 30, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants