FDRS Support for timekeeping - 2024 version

[aviateur17]

Add gateway time keeping, NTP, RTC support

For Gateways, add time keeping in all nodes - MQTT, serial, ESP-NOW, LoRa.
Add support to fetch time via NTP if WiFi is enabled.

Add support for I2C RTC devices - DS3231 and DS1307 and compatible

Gateway will only send time out via serial if WiFi or RTC is in use to prevent loop. Don't want serial node to send time back to WiFi/MQTT node.

Priority in Time master Serial > ESP-NOW > LoRA which means a gateway that is receiving time via serial will reject time via ESP-NOW and LoRA. A gateway that is receiving time via ESP-NOW will reject time via LoRa. If no time is received after 60 minutes then the "master" time server will reset to none.

Automatic transition between daylight savings time and standard time for both US and Europe.

Still need to work on support for controllers and sensors in a future merge Will also verify that compilation works in Arduino environment (I am using VSCode and PlatformIO) Also need to verify compilation against different platforms such as ESP8266, raspberry pi Pico, SAMD21. What other micro-controllers are intended to be supported?

[aviateur17]

Circling back to this. I'm testing LoRa now, and I think the time is working. However there are a few DataReading features that got lost in this change (as far as I can tell). With the old functionality I was able to give the gateway more than a packet's worth (30-40+) of DRs and the asyncRelease would split them into several packets and send them to each destination sequentially. It seems your new functionality only supports a single LoRa packet to each recipient, which is not sufficient.

The code I've submitted does the same thing. Basically it looks at all of the data in the queue, and for all data that is going to the same destination address, it sends that information together.

so in fdrs_lora.h line 830 we check if the buffer is not empty meaning there is data to be sent

line 837, if there is no existing data to be sent then we load new data to be sent (existing data would be LoRa retries) line 841, we load new data to be sent via malloc. We know how many are to be sent via the previous call on line 839. The transmitSameLoRa function looks at the queue and finds the number of DataReadings that are going to the same destination address and computes that number of DRs. Now that we know the number we can allocate memory for that number of DataReadings on line 841. Then, on line 843 to 845 in the for loop we populate the data to be sent via the for loop. Take the data from the queue and mark it to be sent. This can have up to len size DataReadings (more than 1 DataReading). Then on line 846 we populate the address to be sent to. Line 848 releases the data from the queue or buffer. Now, depending upon whether we want an ACK or not, we send the data (len size DataReadings) via line 856 (no ACK) or line 866 (ACKs).

I've tested the functionality (via the LoRa Stress test sketch that is included) and I can see that it will send upwards of 10+ DataReadings at the same time.

Another behavior I noticed, but didn't look into closely yet was the way that DataReadings are sent via LoRa instantaneously upon arrival. The previous behavior was to save, combine and release them at a set interval. This was to limit radio chatter mostly, and to prepare to add channel activity detection (which would delay the release until the channel was clear). It also leaves it upon the user to set the delay in accordance with their local regulations regarding airtime and duty-cycle. I will have to look closer at your code. I guess I don't fully understand how your new buffering system works yet. Let me know if I'm misunderstanding things so far.

The TxDelay does this as well. If there are more than 1 DataReadings that accrue in that delay time and they are all going to the same destination then the PR code will group them all together and attempt to send them at the same time.

The delay could be increased, if need be, to accommodate regulatory requirements. The longer the TxDelay the more time between transmissions.

I've always considered that short SystemPackets, when sent individually, are an acceptable exception to that set transmission cycle.

I attempted this - excluding the SPs from the delay - and found that when I transmit a ping followed by a time request followed by DRs there is not enough receive time to reliably get the ping response. Therefore, because of that testing, I decided that there should be some airtime between SP transmits as well.

state_t was in use by RadioLib so I changed it to pingstate_t.

Thanks!

[aviateur17]

I've always considered that short SystemPackets, when sent individually, are an acceptable exception to that set transmission cycle.

I attempted this - excluding the SPs from the delay - and found that when I transmit a ping followed by a time request followed by DRs there is not enough receive time to reliably get the ping response. Therefore, because of that testing, I decided that there should be some airtime between SP transmits as well.

Just to elaborate a bit more on this. I did write some code that attempts to send pings and, I believe, time requests in a synchronous manner (waiting for replies with a while loop), and if that is not possible (not possible if there is currently a DR transmission in process) then it queues up those requests. I would imagine that the majority of the time the pings and time requests would be sent synchronously and especially if you do them before performing sendFDRS().

see fdrs_lora.h line 664 - pingRequestLoRa() lines 672 through 698 and fdrs_lora.h line 891 reqTimeLoRa() lines 895 through 898. Those are the "synchronous" transmits if there is nothing else (loraTxState == stReady) being sent.

[aviateur17]

I guess this brings up a general question: Is it better to send a large amount of shorter packets, or a small amount of larger packets? Might be something to consult the Meshtastic community about. I'm definitely all ears if you have thoughts.

In my mind this depends upon the regulatory requirements (laws in the area), how reliable longer transmissions are as compared to shorter transmissions, and what, if any, loss in control this has on the micro controller. For the latter, the longer the transmits are the more execution needs to be done when the transmission completes. The more features that are added to the project the more critical it will be to "service" those features in a more timely and regular manner. While I was doing that stress testing it seems like 10 DRs was taking about 200ms of transmission time. It doesn't seem like that would be prohibitive at this point.

[timmbogner]

I think a point we're differing on is how many DRs is "a lot". As users scale up their systems, there could be a load of 30+ DataReadings arriving at a gateway at a time. Currently, I simulate this by inserting 30 JSON DataReadings into the console of 0x01, and send them via ESP-NOW to an 0x02 ESPNOW/LoRa gateway. The response when trying to re-transmit them with LoRa is as follows:

10:12:22.382 ->     Incoming ESP-NOW Data Reading from 0x1
10:12:22.382 ->     Sending DR to ESP-NOW Neighbor #2
10:12:22.382 ->     Sending DR to ESP-NOW peers.
10:12:22.382 ->     Sending to LoRa neighbor buffer
10:12:22.382 -> [2] DR added to LoRa buffer. start: 17 end: 12
10:12:22.382 ->     Sending to LoRa broadcast buffer
10:12:22.382 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.421 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 ->     Lora DR Buffer Overflow!
10:12:22.449 -> [2] DR added to LoRa buffer. start: 8 end: 7
10:12:22.495 -> [2] Length: 4 Address: 0xee03 Data:
10:12:22.495 ->     Sending LoRa DR
10:12:22.495 -> [1] Transmitting LoRa message of size 34 bytes with CRC 0x8be7 to destination 0xee03
10:12:22.530 -> [1] LoRa airtime: 75ms
10:12:22.778 -> [2] Length: 30 Address: 0xffff Data:
10:12:22.778 ->     Sending LoRa DR
10:12:22.778 -> [1] Transmitting LoRa message of size 216 bytes with CRC 0xab19 to destination 0xffff
10:12:23.111 -> [1] LoRa airtime: 342ms
10:17:01.390 ->     Local date/time is: Wed Mar  6 10:16:58 2024 STD

# For your copying convenience, here is a sample array of 30 json DRs:

[{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 },{ id: 1, type: 6, data: 384 }]

[aviateur17]

I think a point we're differing on is how many DRs is "a lot". As users scale up their systems, there could be a load of 30+ DataReadings arriving at a gateway at a time. Currently, I simulate this by inserting 30 JSON DataReadings into the console of 0x01, and send them via ESP-NOW to an 0x02 ESPNOW/LoRa gateway.

Sounds good, so I think the first thing to do then is make the queue/buffer larger. In fdrs_lora.h line 14 I make the buffer size 250/7 = 35. We can definitely make that larger to something like 70 pretty easily by changing that line 14. This will clear up the buffer full messages.

Then we have the issue of limiting the amount of LoRa data transmitted to the maximum data size of the LoRa packets. I believe this is around 255 bytes or about 35 DataReadings, if I recall correctly. I don't believe there is any limitation on the number of DRs to be sent (size is len) so we should probably add some code to check for the upper bound of len > 35 so that we only send 35 DataReadings at one time.

I guess this could be done in the transmitSameAddrLoRa() function (fdrs_lora.h line 380) at the return statement:

if(count > (250/sizeof(DataReading)) {
        return (250/sizeof(DataReading));
    }
    else {
        return count;
    }

Edit: 250/sizeof(DataReading) is also called LORASIZE so use this instead:

if(count >  LORASIZE ) {
        return LORASIZE;
    }
    else {
        return count;
    }

[timmbogner]

Okay I just realized ESP-NOW actually isn't splitting large packets correctly either. I'll need to look at that.

BUT 😅 If on the main branch you go directly from serial to LoRa, and you paste in 36+ DataReadings, you will see it split the data into two packets and send them sequentially as follows. This behavior needs to be kept up. I'll look into ESP-NOW.

10:42:33.065 ->     Incoming Serial.
10:42:33.065 ->     Sending to LoRa broadcast buffer
10:42:37.241 ->     Transmitting LoRa message of size 251 bytes with CRC 0xea6e to LoRa MAC 0xffff
10:42:37.618 ->     Transmitting LoRa message of size 13 bytes with CRC 0xea8f to LoRa MAC 0xffff
10:42:37.658 ->     LoRa airtime: 440ms

[aviateur17]

Okay I just realized ESP-NOW actually isn't splitting large packets correctly either. I'll need to look at that.

I believe ESP-NOW does handle this. fdrs_gateway_espnow.h line 408:

if(ln > espnow_size) {

This limits the transmission size to maximum ESP-NOW data transmission size.

This behavior needs to be kept up.

Yep, for sure

[timmbogner]

I believe ESP-NOW does handle this.

Ah, I was still testing in the main branch, so I guess you fixed it. Thanks! I'm still digesting the changes to ESP-NOW, so bear with me.

I'm going to commit the adjustments I have made so far, then continue testing the actual time portion.

[timmbogner]

Yeah, I implemented an asynchronous ping so it will just output the result to the screen. What we could do, and Håkan's post gave me this idea, would be to implement a callback function when we get either a ping or a ping timeout and then we can send the ping time or lack of time to the callback function. That way something can be done in response. What do you think about that?

Another circle-back: Not sure if this is what you are describing... Would it be feasible to make a blocking ping function, just for the user to have access to, and it simply yields and runs the loop tasks until it gets a ping response or times out? Looking at the code, recvPingEspNow(incMAC); is run inside of the ESP-NOW callback. If I'm not mistaken, that means as long as you yield to the system, it will be executed as soon as a ping response comes in. Can we have it set a flag in recvPingEspNow() and pingRequestLoRa(), then wait for that flag at the end of the node's pingFDRS()? Also instead of clearing the espNowPing and loraPing structures, leave them intact and use the response time as the return of pingFDRS().

Prototype:

int pingFDRS(uint32_t timeout)
{
  global_ping_flag = false;
#ifdef USE_ESPNOW
  pingFDRSEspNow(gatewayAddress, timeout);
#endif
#ifdef USE_LORA
  pingRequestLoRa(gtwyAddress, timeout);
#endif
while (!global_ping_flag){
  yield();
  handleLoRa();
}
 // do some stuff to get the response time
  return response_time;
}

There will need to be something add to handle timeouts, but I think this illustrates what I'm hoping to do.

[aviateur17]

Yeah, I implemented an asynchronous ping so it will just output the result to the screen. What we could do, and Håkan's post gave me this idea, would be to implement a callback function when we get either a ping or a ping timeout and then we can send the ping time or lack of time to the callback function. That way something can be done in response. What do you think about that?

Another circle-back: Not sure if this is what you are describing... Would it be feasible to make a blocking ping function, just for the user to have access to, and it simply yields and runs the loop tasks until it gets a ping response or times out? Looking at the code, recvPingEspNow(incMAC); is run inside of the ESP-NOW callback. If I'm not mistaken, that means as long as you yield to the system, it will be executed as soon as a ping response comes in. Can we have it set a flag in recvPingEspNow() and pingRequestLoRa(), then wait for that flag at the end of the node's pingFDRS()? Also instead of clearing the espNowPing and loraPing structures, leave them intact and use the response time as the return of pingFDRS().

Prototype:

int pingFDRS(uint32_t timeout)
{
  global_ping_flag = false;
#ifdef USE_ESPNOW
  pingFDRSEspNow(gatewayAddress, timeout);
#endif
#ifdef USE_LORA
  pingRequestLoRa(gtwyAddress, timeout);
#endif
while (!global_ping_flag){
  yield();
  handleLoRa();
}
 // do some stuff to get the response time
  return response_time;
}

There will need to be something add to handle timeouts, but I think this illustrates what I'm hoping to do.

I wrote the following over several hours so it may be a little jumbled up...

I think the issue is not the ending part of the synchronous or blocking function it's the beginning part of it. Once it's called we can execute it without issue it's just when calling it we need to make sure there is no async function already running. That's why, in the LoRa ping code, I check to see if we are waiting for an ACK and if so, instead of running the ping right away, I queue up the ping for later execution. If we didn't check for that we might miss the ACK and the ping response both. If we ran the following code in a node..

pingFDRS();
reqTimeFDRS();
subscribeFDRS();
loadFDRS();
loadFDRS();
sendFDRS();

There are at least 4 LoRa transmits there. When in that order there should be no issues running the synchronous code, but what if we ran it in this order.

loadFDRS();
loadFDRS();
sendFDRS();
pingFDRS();
subscribeFDRS();
reqTimeFDRS();

If everything was synchronous and we are using ACKS then we may miss the ACKS during the ping, subscribe, and time request.

The challenge when using both synchronous (blocking) and asynchronous functions is that when you call the synchronous function it may not be able to do what it needs to do right away due to an asynchronous function already in process. So, for example, in LoRA, the transmissions of the DataReadings when using ACKS are asynchronous (if they were synchronous they may block for like 1 second or so). If they are ongoing and then there is a call to a ping which is synchronous then we either cannot execute the ping or we have to wait and execute it later after the asynchronous task is completed. With LoRa this is only complicated when ACKs are enabled as those require listening for responses and then potentially transmitting again. So what I do in the ping and time request functions is to check to see if an Asynchronous task is running and if so I would queue up the ping for transmission later. If you call this ping function that could be asynchronous there is no guarantee that it will return a value.

What do you think about a callback function where when the ping completes, a function is called that can print to the output the ping response time and also hand that value to other code if you want to do something else with that value? I see what information you desire but I'm not clear why it's needed as a response to pingFDRS and a callback function can't be used. It might help if you could clarify what you're going to use the ping response time for. I think pingFDRS returning a value makes everything clean and easy to understand. Maybe what we could do is return a response value when the ping is performed synchronously and then just return 0 or some very high number when the ping is performed asynchronously.

Looking at the code, recvPingEspNow(incMAC); is run inside of the ESP-NOW callback. If I'm not mistaken, that means as long as you yield to the system, it will be executed as soon as a ping response comes in

I think that's the magic of using ESP-NOW and the second core. I think it generates an interrupt saying that there is a ESP-NOW response and then calls the callback function therefore that works when you're spinning in a while loop waiting for a response.

Can we have it set a flag in recvPingEspNow() and pingRequestLoRa(), then wait for that flag at the end of the node's pingFDRS()?

If you're spinning in a while loop in pingFDRS waiting for a response I don't think there's any other way to execute other code in general and wait for a response at the same time.

I think a callback function would work but I'm open to doing what you think.

[timmbogner]

I've realized that this ping stuff is a relatively minor feature, and the main reason I want to keep it is because it already exists in the old version. In reality, I must admit that being able to actually use the ping time is a fringe-feature. Few people will need it, although it is nice to have. I think the callback is just too much extra stuff for too little real benefit. I also finally understand why the blocking/async thing is a problem. Thanks for explaining it so clearly. My method could work if there was a way to like, return -1 if there was error sending (it would fail if there was a transmission in progress). Even then though, I think it may be more trouble than it's worth.

So basically, I don't care too much about keeping the ability to use the ping time. Displaying is what most users will need, if they even use the ping functionality in the first place. You are welcome to implement your callback idea if you want, as long as it doesn't add much config overhead. Sorry for flip-flopping here!

[aviateur17]

Sounds good, I'll fix up the ping stuff today (making them return int - both ESP-NOW and LoRa) and then do some more testing.

[aviateur17]

Working on web page to set time, change debug level dynamically at runtime, and show debug output.

[timmbogner]

I really like the webpage thing. Did you have to change DBG level from a macro to be configurable after compile? I've discussed a SystemPacket command that would drop any gateway into WiFi mode for OTA programming. If we changed configurations to be settable after compile (stored in flash/eeprom), we could invoke a captive portal to a page like yours with full configuration options. Configuration-in-the-field is an ages old request for FDRS. Let's keep it simple for this PR, but I like the HTML backend concept a lot.

I think I should have time for testing in the next week. After that I'll be on the road until roughly the end of the month.

[aviateur17]

I really like the webpage thing. Did you have to change DBG level from a macro to be configurable after compile? I've discussed a SystemPacket command that would drop any gateway into WiFi mode for OTA programming.

I was thinking about that as well. Would be a lot of work but this makes it easier.

If we changed configurations to be settable after compile (stored in flash/eeprom), we could invoke a captive portal to a page like yours with full configuration options. Configuration-in-the-field is an ages old request for FDRS. Let's keep it simple for this PR, but I like the HTML backend concept a lot.

I think I Just wanted to show you what I'm up to next. I think I'd rather be done with this PR and keep this to the next PR.

I think I should have time for testing in the next week. After that I'll be on the road until roughly the end of the month.

Sounds good, no rush. I don't think I'm planning on submitting any more to this PR unless I find bugs.

Edit: Basically what I did was define a global variable like debug level based on the value of some preprocessor macros. like

#if DEBUG_LEVEL == 2
int debug_level = 2
#endif

[timmbogner]

I'm still here! When I left off a few weeks ago, the gateway functionality was tested with no issues. I will be testing nodes in the next week or so.

[timmbogner]

@aviateur17 I finally solved the conflicts; maybe even correctly! It wasn't as painful as I'd anticipated. Please check over things to make sure I didn't unleash any unanticipated chaos 😅

The last thing I want to do is create a simple example of how to use the time data. The T-Watch sketch is a bit convoluted. I'm thinking just something that delivers each element of the time individually over the serial monitor. This can act as a framework that a user can adapt to a TFT/7-segment/OLED or whatever kind of clock display they desire to build.

If you have anything like that ready to go, or you'd like to contribute this, obviously please go for it! I plan to do it sometime, but I am not going to delay this PR any further either way. As long as this merge didn't break anything, I think the PR is ready to go!

[aviateur17]

Timm, sounds good. It may take a couple of weeks as I don't have a lot of time right now but I'll check it out and make comments to keep up to date.

[aviateur17]

Output from Controller Time example to be submitted shortly:

The timestamps in front are my personal added code so won't be shown.

Edit: Added daylight savings time (shown in below output).

20422 |     FDRS ControllerTime example.
[ 30464][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
[ 30464][E][esp32-hal-gpio.c:102] __pinMode(): Invalid pin selected
E (30462) gpio: gpio_set_level(227): GPIO output gpio_num error
E (30497) gpio: gpio_set_level(227): GPIO output gpio_num error
[ 30500][W][Wire.cpp:301] begin(): Bus already started in Master Mode.
30530 |     Display initialized!
30554 |     Hello, World!
30595 |     FDRS User Node initializing...
30636 |      Reading ID 85
30676 |      Gateway: 21
30717 |     Initializing ESP-NOW!
30757 |     Failed to add peer bcast
30798 |     Requesting time from gateway
30838 | [1] Requesting time from gateway 0x21
30845 | [2] Incoming ESP-NOW System Packet from 0x21
30845 | [1] Received time via ESP-NOW from 0x21
30846 | [1] ESP-NOW time source is now 0x21
30856 | [1] Time adjust 1714575195 secs
30856 | [1] Time change from STD -> DST
1714576459 |     Configured Standard Time offset from UTC: -6 hours.
1714576459 |     Configured Daylight Savings Time offset from UTC: -5 hours.
1714576459 |     ---- strftime() function output ----
1714576459 |     Local date/time is: Wed May  1 10:14:20 2024 DST
1714576459 |     Year: 2024
1714576459 |     Month: 05
1714576459 |     Month Name: May
1714576459 |     Day of Month: 01
1714576459 |     Day of Week: 3
1714576459 |     Day Name: Wednesday
1714576459 |     Day of Year: 122
1714576459 |     Hour (24 hour format): 10
1714576459 |     Hour (12 hour format): 10
1714576459 |     Minute: 14
1714576459 |     Second: 20
1714576459 |     AM/PM: AM
1714576459 |     Daylight Savings:  DST (yes)
1714576459 |     US format: Wednesday, 05/01/2024 10:14:20 AM DST
1714576459 |     European format: Wednesday, 01/05/2024 10:14:20 DST
1714576459 |     ---- struct tm output ----
1714576459 |     Year: 2024
1714576459 |     Month: 5
1714576459 |     Month Name: May
1714576459 |     Day of Month: 1
1714576459 |     Day of Week: 3
1714576459 |     Day Name: Wednesday
1714576459 |     Day of Year: 122
1714576459 |     Hour (24 hour format):10
1714576459 |     Hour (12 hour format):10 AM
1714576459 |     Minute: 14
1714576459 |     Second: 20
1714576459 |     Daylight Savings:  DST (yes)
1714576459 |     Local Time: Wednesday, 5/1/2024 10:14:20 AM DST

[aviateur17]

Timm, the merge seems to be good based on my review of your commit. I think there may be an issue from my doing in the node_espnow code in the pingEspNow function. Let me review that and make sure everything compiles properly.

[aviateur17]

Timm, I just made the changes mentioned earlier. I think we're good to go.

[timmbogner]

I'm going to merge this (sorry it's taken so long), but I still need to add to the documentation. I'll get to that once my springtime work dies down.

I noticed that LilyGo has a new T-Watch with an integrated LoRa radio. I'm excited to order one, and I'd love to send you one too as a token of my thanks for everything you do for FDRS. Email me if you're interested!