ESP32-PaxCounter/src/timesync.cpp

250 lines
8.5 KiB
C++
Raw Normal View History

2019-03-09 00:53:11 +01:00
/*
2019-03-09 00:54:34 +01:00
///--> IMPORTANT LICENSE NOTE for this file <--///
2019-03-09 00:53:11 +01:00
PLEASE NOTE: There is a patent filed for the time sync algorithm used in the
2019-03-09 00:54:34 +01:00
code of this file. The shown implementation example is covered by the
2019-03-09 00:53:11 +01:00
repository's licencse, but you may not be eligible to deploy the applied
2019-03-10 17:35:57 +01:00
algorithm in applications without granted license by the patent holder.
2019-03-09 00:53:11 +01:00
*/
#ifdef TIME_SYNC_TIMESERVER
#include "timesync.h"
2019-03-14 00:05:19 +01:00
using namespace std::chrono;
2019-03-09 00:53:11 +01:00
// Local logging tag
static const char TAG[] = __FILE__;
2019-03-09 20:40:21 +01:00
TaskHandle_t timeSyncReqTask;
2019-03-12 23:50:02 +01:00
2019-03-17 19:24:50 +01:00
static uint8_t time_sync_seqNo = 0;
static bool lora_time_sync_pending = false;
2019-03-12 23:50:02 +01:00
typedef std::chrono::system_clock myClock;
typedef myClock::time_point myClock_timepoint;
typedef std::chrono::duration<long long int, std::ratio<1, 1000>>
myClock_msecTick;
2019-03-16 21:01:43 +01:00
typedef std::chrono::duration<double> myClock_secTick;
2019-03-13 20:20:19 +01:00
2019-03-12 23:50:02 +01:00
myClock_timepoint time_sync_tx[TIME_SYNC_SAMPLES];
myClock_timepoint time_sync_rx[TIME_SYNC_SAMPLES];
2019-03-09 00:53:11 +01:00
// send time request message
2019-03-12 23:50:02 +01:00
void send_timesync_req() {
2019-03-09 00:53:11 +01:00
// if a timesync handshake is pending then exit
2019-03-12 23:50:02 +01:00
if (lora_time_sync_pending) {
2019-03-19 00:02:35 +01:00
// ESP_LOGI(TAG, "Timeserver sync request already pending");
2019-03-09 00:53:11 +01:00
return;
} else {
2019-03-16 21:01:43 +01:00
ESP_LOGI(TAG, "[%0.3f] Timeserver sync request started", millis() / 1000.0);
2019-03-09 00:53:11 +01:00
2019-03-12 23:50:02 +01:00
lora_time_sync_pending = true;
2019-03-09 20:40:21 +01:00
2019-03-17 19:24:50 +01:00
// clear timestamp array
for (uint8_t i = 0; i < TIME_SYNC_SAMPLES; i++)
2019-03-16 21:01:43 +01:00
time_sync_tx[i] = time_sync_rx[i] = myClock_timepoint();
2019-03-09 00:53:11 +01:00
2019-03-09 20:40:21 +01:00
// kick off temporary task for timeserver handshake processing
2019-03-09 00:53:11 +01:00
if (!timeSyncReqTask)
2019-03-12 23:50:02 +01:00
xTaskCreatePinnedToCore(process_timesync_req, // task function
"timesync_req", // name of task
2048, // stack size of task
(void *)1, // task parameter
2019-03-16 21:01:43 +01:00
4, // priority of the task
2019-03-12 23:50:02 +01:00
&timeSyncReqTask, // task handle
1); // CPU core
2019-03-09 00:53:11 +01:00
}
}
// task for sending time sync requests
2019-03-12 23:50:02 +01:00
void process_timesync_req(void *taskparameter) {
2019-03-09 20:40:21 +01:00
2019-03-17 19:24:50 +01:00
uint32_t seq_no = 0, time_to_set_us, time_to_set_ms;
2019-03-16 21:01:43 +01:00
uint16_t time_to_set_fraction_msec;
2019-03-17 19:24:50 +01:00
uint8_t k = 0, i = 0;
2019-03-14 19:52:10 +01:00
time_t time_to_set;
2019-03-17 19:24:50 +01:00
auto time_offset = myClock_msecTick::zero();
2019-03-16 21:01:43 +01:00
// wait until we are joined
while (!LMIC.devaddr) {
vTaskDelay(pdMS_TO_TICKS(2000));
}
2019-03-09 20:40:21 +01:00
2019-03-09 00:53:11 +01:00
// enqueue timestamp samples in lora sendqueue
2019-03-17 19:24:50 +01:00
for (uint8_t i = 0; i < TIME_SYNC_SAMPLES; i++) {
2019-03-09 20:40:21 +01:00
// wrap around seqNo 0 .. 254
2019-03-19 20:50:00 +01:00
time_sync_seqNo = (time_sync_seqNo < 255) ? time_sync_seqNo + 1 : 0;
2019-03-09 20:40:21 +01:00
// send sync request to server
2019-03-09 00:53:11 +01:00
payload.reset();
2019-03-09 22:08:57 +01:00
payload.addByte(time_sync_seqNo);
2019-03-09 00:53:11 +01:00
SendPayload(TIMEPORT, prio_high);
2019-03-16 21:01:43 +01:00
// process answer, wait for notification from recv_timesync_ans()
2019-03-09 15:25:44 +01:00
if ((xTaskNotifyWait(0x00, ULONG_MAX, &seq_no,
2019-03-12 23:50:02 +01:00
pdMS_TO_TICKS(TIME_SYNC_TIMEOUT * 1000)) == pdFALSE) ||
2019-03-09 20:40:21 +01:00
(seq_no != time_sync_seqNo)) {
2019-03-12 23:50:02 +01:00
2019-03-19 00:02:35 +01:00
ESP_LOGW(TAG, "[%0.3f] Timeserver error: handshake timed out",
millis() / 1000.0);
2019-03-09 20:40:21 +01:00
goto finish;
} // no valid sequence received before timeout
2019-03-12 23:50:02 +01:00
else { // calculate time diff from collected timestamps
2019-03-11 01:05:41 +01:00
k = seq_no % TIME_SYNC_SAMPLES;
2019-03-14 00:05:19 +01:00
auto t_tx = time_point_cast<milliseconds>(
2019-03-13 20:20:19 +01:00
time_sync_tx[k]); // timepoint when node TX_completed
2019-03-14 00:05:19 +01:00
auto t_rx = time_point_cast<milliseconds>(
2019-03-12 23:50:02 +01:00
time_sync_rx[k]); // timepoint when message was seen on gateway
2019-03-11 01:05:41 +01:00
2019-03-13 20:20:19 +01:00
time_offset += t_rx - t_tx; // cumulate timepoint diffs
2019-03-11 01:05:41 +01:00
2019-03-16 21:01:43 +01:00
if (i < TIME_SYNC_SAMPLES - 1) {
// wait until next cycle
2019-03-12 23:50:02 +01:00
vTaskDelay(pdMS_TO_TICKS(TIME_SYNC_CYCLE * 1000));
2019-03-16 21:01:43 +01:00
} else {
2019-03-19 01:46:20 +01:00
// send flush to open a receive window for last time_sync_answer
// payload.reset();
// payload.addByte(0x99);
// SendPayload(RCMDPORT, prio_high);
// Send a payload-less message to open a receive window for last
// time_sync_answer
void LMIC_sendAlive();
2019-03-16 21:01:43 +01:00
}
2019-03-09 15:25:44 +01:00
}
2019-03-10 17:35:57 +01:00
} // for
2019-03-09 00:53:11 +01:00
2019-03-16 21:01:43 +01:00
// calculate time offset from collected diffs
2019-03-14 19:52:10 +01:00
time_offset /= TIME_SYNC_SAMPLES;
2019-03-16 21:01:43 +01:00
ESP_LOGD(TAG, "[%0.3f] avg time diff: %0.3f sec", millis() / 1000.0,
myClock_secTick(time_offset).count());
2019-03-17 19:24:50 +01:00
// calculate absolute time offset with millisecond precision using time base
// of LMIC os, since we use LMIC's ostime_t txEnd as tx timestamp
time_offset += milliseconds(osticks2ms(os_getTime()));
2019-03-17 22:00:42 +01:00
// apply calibration factor for processing time
time_offset += milliseconds(TIME_SYNC_FIXUP);
2019-03-16 21:01:43 +01:00
// convert to seconds
2019-03-17 19:24:50 +01:00
time_to_set = static_cast<time_t>(myClock_secTick(time_offset).count());
2019-03-16 21:01:43 +01:00
// calculate fraction milliseconds
2019-03-17 19:24:50 +01:00
time_to_set_fraction_msec = static_cast<uint16_t>(time_offset.count() % 1000);
2019-03-16 21:01:43 +01:00
ESP_LOGD(TAG, "[%0.3f] Calculated UTC epoch time: %d.%03d sec",
millis() / 1000.0, time_to_set, time_to_set_fraction_msec);
2019-03-09 15:25:44 +01:00
2019-03-14 19:52:10 +01:00
// adjust system time
if (timeIsValid(time_to_set)) {
if (abs(time_offset.count()) >=
TIME_SYNC_TRIGGER) { // milliseconds threshold
2019-03-14 00:05:19 +01:00
// wait until top of second
2019-03-17 22:00:42 +01:00
uint16_t const wait_ms = 1000 - time_to_set_fraction_msec;
ESP_LOGD(TAG, "[%0.3f] waiting %d ms", millis() / 1000.0, wait_ms);
vTaskDelay(pdMS_TO_TICKS(wait_ms));
2019-03-14 00:05:19 +01:00
2019-03-19 01:46:20 +01:00
#if !defined(GPS_INT) && !defined(RTC_INT)
2019-03-19 20:50:00 +01:00
// sync esp32 hardware timer based pps to top of second
2019-03-19 01:46:20 +01:00
timerRestart(ppsIRQ); // reset pps timer
CLOCKIRQ(); // fire clock pps interrupt
time_to_set++; // advance time 1 second
#endif
setTime(time_to_set); // set the time on top of second
2019-03-14 00:05:19 +01:00
2019-03-17 19:24:50 +01:00
#ifdef HAS_RTC
set_rtctime(time_to_set); // calibrate RTC if we have one
#endif
2019-03-16 21:01:43 +01:00
2019-03-17 19:24:50 +01:00
timeSource = _lora;
2019-03-09 15:25:44 +01:00
timesyncer.attach(TIME_SYNC_INTERVAL * 60,
timeSync); // set to regular repeat
2019-03-16 21:01:43 +01:00
ESP_LOGI(TAG, "[%0.3f] Timesync finished, time adjusted by %.3f sec",
millis() / 1000.0, myClock_secTick(time_offset).count());
2019-03-09 00:53:11 +01:00
} else
2019-03-19 01:46:20 +01:00
ESP_LOGI(TAG, "[%0.3f] Timesync finished, time is up to date",
2019-03-19 00:02:35 +01:00
millis() / 1000.0);
2019-03-09 15:25:44 +01:00
} else
2019-03-19 00:02:35 +01:00
ESP_LOGW(TAG, "[%0.3f] Timesync failed, outdated time calculated",
millis() / 1000.0);
2019-03-09 15:25:44 +01:00
finish:
2019-03-09 00:53:11 +01:00
2019-03-12 23:50:02 +01:00
lora_time_sync_pending = false;
2019-03-09 20:40:21 +01:00
timeSyncReqTask = NULL;
2019-03-09 00:53:11 +01:00
vTaskDelete(NULL); // end task
}
2019-03-10 17:35:57 +01:00
// called from lorawan.cpp after time_sync_req was sent
2019-03-17 19:24:50 +01:00
void store_time_sync_req(uint32_t t_txEnd_ms) {
2019-03-12 23:50:02 +01:00
2019-03-17 19:24:50 +01:00
uint8_t k = time_sync_seqNo % TIME_SYNC_SAMPLES;
2019-03-17 15:04:11 +01:00
2019-03-17 19:24:50 +01:00
time_sync_tx[k] += milliseconds(t_txEnd_ms);
2019-03-09 15:25:44 +01:00
2019-03-16 21:01:43 +01:00
ESP_LOGD(TAG, "[%0.3f] Timesync request #%d sent at %d.%03d",
2019-03-17 19:24:50 +01:00
millis() / 1000.0, time_sync_seqNo, t_txEnd_ms / 1000,
t_txEnd_ms % 1000);
2019-03-16 21:01:43 +01:00
}
// process timeserver timestamp answer, called from lorawan.cpp
int recv_timesync_ans(uint8_t buf[], uint8_t buf_len) {
// if no timesync handshake is pending or spurious buffer then exit
2019-03-19 00:02:35 +01:00
if (!lora_time_sync_pending)
2019-03-16 21:01:43 +01:00
return 0; // failure
2019-03-19 00:02:35 +01:00
// if no time is available or spurious buffer then exit
if (buf_len != TIME_SYNC_FRAME_LENGTH) {
if (buf[0] == 0xff)
ESP_LOGI(TAG, "[%0.3f] Timeserver error: no confident time available",
millis() / 1000.0);
else
ESP_LOGW(TAG, "[%0.3f] Timeserver error: spurious data received",
millis() / 1000.0);
return 0; // failure
}
else { // we received a probably valid time frame
uint8_t seq_no = buf[0], k = seq_no % TIME_SYNC_SAMPLES;
uint16_t timestamp_msec; // convert 1/250th sec fractions to ms
uint32_t timestamp_sec;
2019-03-16 21:01:43 +01:00
2019-03-19 01:46:20 +01:00
// fetch timeserver time from 4 bytes containing the UTC seconds since
// unix epoch. Octet order is big endian. Casts are necessary, because buf
// is an array of single byte values, and they might overflow when shifted
2019-03-19 00:02:35 +01:00
timestamp_sec = ((uint32_t)buf[4]) | (((uint32_t)buf[3]) << 8) |
(((uint32_t)buf[2]) << 16) | (((uint32_t)buf[1]) << 24);
2019-03-16 22:16:55 +01:00
2019-03-19 00:02:35 +01:00
// the 5th byte contains the fractional seconds in 2^-8 second steps
timestamp_msec = 4 * buf[5];
2019-03-16 21:01:43 +01:00
2019-03-19 00:02:35 +01:00
// construct the timepoint when message was seen on gateway
2019-03-16 21:01:43 +01:00
time_sync_rx[k] += seconds(timestamp_sec) + milliseconds(timestamp_msec);
2019-03-19 00:02:35 +01:00
// guess if the timepoint is recent by comparing with code compile date
if (timeIsValid(myClock::to_time_t(time_sync_rx[k]))) {
ESP_LOGD(TAG, "[%0.3f] Timesync request #%d rcvd at %d.%03d",
millis() / 1000.0, seq_no, timestamp_sec, timestamp_msec);
2019-03-16 21:01:43 +01:00
2019-03-19 00:02:35 +01:00
// inform processing task
if (timeSyncReqTask)
xTaskNotify(timeSyncReqTask, seq_no, eSetBits);
2019-03-16 21:01:43 +01:00
2019-03-19 00:02:35 +01:00
return 1; // success
} else {
ESP_LOGW(TAG, "[%0.3f] Timeserver error: outdated time received",
millis() / 1000.0);
return 0; // failure
}
}
2019-03-09 15:25:44 +01:00
}
2019-03-09 00:53:11 +01:00
#endif