RTC clock drifts ahead and causes Adafruit IO error "data created_at may not be in the future"

[lornova]

On one of my Enviro boards the RTC drifts ahead and eventually causes an error while uploading readings to Adafruit IO.
The last reading is rejected with the error "422 Unprocessable Entity: data created_at may not be in the future" and a banner appears on the Adafruit IO web site.
I have patched main.py to resync the clock when any upload error is returned (I don't think that there is a way to tell this specific error from other 422 error conditions).
This is my patch, but it should be improved:

    # if we have enough cached uploads...
    if enviro.is_upload_needed():
      enviro.logging.info(f"> {enviro.cached_upload_count()} cache file(s) need uploading")
      if not enviro.upload_readings():
+        # try to resync RTC to avoid errors caused by drifting clock
+        # (422 Unprocessable Entity: data created_at may not be in the future)
+        enviro.sync_clock_from_ntp()
        enviro.halt("! reading upload failed")

At the next upload cycle the issue is gone, but periodically it will happen again when the RTC drifts enough time ahead. To avoid the issue completely the RTC should be resynced periodically.

[ZodiusInfuser]

Hi @lornova. Have a look at this pull request I raised last month: #132

It has handling for this error case, as well as periodic RTC updating. It's not merged yet as I was hoping more people would test it to confirm it's good. Perhaps you can give it a try if you have time?

[lornova]

Hi @lornova. Have a look at this pull request I raised last month: #132

It has handling for this error case, as well as periodic RTC updating. It's not merged yet as I was hoping more people would test it to confirm it's good. Perhaps you can give it a try if you have time?

Hi @ZodiusInfuser, I've been using your patch for a while, but unfortunately the issue comes back very quickly:

MQTT ERROR: error saving data to lornova/groups/enviro, data created_at may not be in the future

Apparently the RTC is drifting very quickly. So I suggest to use a lower default resync setting (currently is 1 week, I would probably lower it to 2 days).

[ZodiusInfuser]

Hi @lornova, thanks for testing the patch (which is now part of the main firmware). Hmm, I really would have thought that 1 week would have been enough to correct any drift before that error occurs. I'd ideally like more testing to be done before changing the default value. Is that 2 days based on your experiments or just a feeling?

Fortunately, it's not too bad if the error occurs, as the firmware detects it and automatically resyncs. The failed upload will then get uploaded successfully the next time the board wakes, whereas beforehand there was no handling.

[lornova]

Well it's more than a feeling, as I got the error back after two days... But of course that's not a statistically significative sample...

In my case it is a bad error, because I have 4 enviro devices running (2 indoor, 1 urban, 1 weather), all with a reading_frequency of 15 minutes and an upload_frequency of 1 hour. I synchronized them to upload to Adafruit IO (which has a data rate limit of 60 data points per minute) at the 4 differents quarter of the hour. If one device gets the "data created_at may not be in the future" will overlap with the next device, so I will get the data throttling issue...

[ZodiusInfuser]

I see. I'm still not sure if the default value needs to be changed, but for your needs the timing can be changed by editing your board's config.py to reduce the resync_frequency.

As for your upload schedule, I will say that its optimistic to expect all of your boards to remain staggered as you have them. Uploads can fail due to external factors, which will cause the staggering to shift. The enviro firmware does detect when data throttling occurs though, so your readings will get uploaded eventually, just perhaps not at the exact time you want.

Maybe support for staggered times should be added 🤔. I'm not sure what the specific requirements would be though. If you have clear ideas for this, you're welcome to have a go and raise a pull request.

[MrDrem]

"support for staggered times should be added" - I'd love for this to be added as an option. I'd love for my uploads to be scheduled for h:02 & h:32 for a couple of reasons.

1. I'd like to move them away from the readings which we know that the WiFi chips increase the temperature on those upload readings.
2. I'd like to have set times so that failed readings don't force me to have to go and press the poke button to get my readings back to the right upload times. I'm trying to tweet off the basis of my readings, I want to do this each hour on the data that I've had over the last hour, and having this set would be a great help.

@ZodiusInfuser would you like me to log this as a separate issue?

[ZodiusInfuser]

@MrDrem Yes please. Would be good to have it visible so community can discuss what features they actually want. No promises that I'll be able to get to it any time soon, but perhaps an enterprising customer would fancy the challenge ;)

[ExperiMentor]

Just to say that I regularly get the "error "422 Unprocessable Entity: data created_at may not be in the future". It occurs unpredictably, but often MUCH sooner than a week. Most often it's less than a day with my board. So I'd suggest ressetting the clock every few hours, if not simply do it with every WiFi connect.