timesync(experimental)

This commit is contained in:
Verkehrsrot 2019-03-09 20:40:21 +01:00
parent c64f087faa
commit 7ab0d8fcd6
4 changed files with 94 additions and 86 deletions

View File

@ -5,15 +5,14 @@
#include "timesync.h" #include "timesync.h"
#include "timekeeper.h" #include "timekeeper.h"
#define TIME_SYNC_SAMPLES 3 // number of time requests for averaging #define TIME_SYNC_SAMPLES 1 // number of time requests for averaging
#define TIME_SYNC_CYCLE 20 // seconds between two time requests #define TIME_SYNC_CYCLE 60 // seconds between two time requests
#define TIME_SYNC_TIMEOUT 180 // timeout seconds waiting for timeserver answer #define TIME_SYNC_TIMEOUT 120 // timeout seconds waiting for timeserver answer
#define TIME_SYNC_THRESHOLD \ #define TIME_SYNC_TRIGGER 1.0f // time deviation threshold triggering time sync
1.0f // time deviation threshold triggering time sync #define TIME_SYNC_START_OPCODE 0x90 // start time sync (server -> node)
#define TIME_SYNC_START_OPCODE 0x90 // start time sync on node #define TIME_SYNC_STEP_OPCODE 0x91 // step to next sync request (node -> server)
#define TIME_SYNC_STOP_OPCODE 0x91 // stop time sync on node #define TIME_SYNC_REQ_OPCODE 0x92 // node request at timeserver (node -> server)
#define TIME_SYNC_REQ_OPCODE 0x92 // node request at timeserver #define TIME_SYNC_ANS_OPCODE 0x93 // timeserver answer to node (server -> node)
#define TIME_SYNC_ANS_OPCODE 0x93 // timeserver answer to node
typedef struct { typedef struct {
uint32_t seconds; uint32_t seconds;
@ -22,11 +21,11 @@ typedef struct {
extern time_sync_message_t time_sync_messages[], time_sync_answers[]; extern time_sync_message_t time_sync_messages[], time_sync_answers[];
extern uint8_t time_sync_seqNo; extern uint8_t time_sync_seqNo;
extern bool time_sync_pending;
void send_Servertime_req(void); void send_Servertime_req(void);
void recv_Servertime_ans(uint8_t val[]); void recv_Servertime_ans(uint8_t val[]);
void process_Servertime_sync_req(void *taskparameter); void process_Servertime_sync_req(void *taskparameter);
void process_Servertime_sync_ans(void *taskparameter);
void force_Servertime_sync(uint8_t val[]); void force_Servertime_sync(uint8_t val[]);
void store_time_sync_req(time_t secs, uint32_t micros); void store_time_sync_req(time_t secs, uint32_t micros);

View File

@ -63,6 +63,18 @@ function Decoder(bytes, port) {
return decode(bytes, [uint16], ['voltage']); return decode(bytes, [uint16], ['voltage']);
} }
if (port === 9) {
// timesync request
if (bytes.length === 1) {
decoded.timesync_opcode = bytes[0];
}
if (bytes.length === 2) {
decoded.timesync_opcode = bytes[0];
decoded.timesync_seqno = bytes[1];
}
return decoded;
}
} }

View File

@ -40,8 +40,16 @@ void SendPayload(uint8_t port, sendprio_t prio) {
// enqueue message in device's send queues // enqueue message in device's send queues
#ifdef HAS_LORA #ifdef HAS_LORA
lora_enqueuedata(&SendBuffer, prio); /*
// pause send any data but timeport data, while timesync handshake is ongoing
if (port != TIMEPORT) {
if (!time_sync_pending)
lora_enqueuedata(&SendBuffer, prio);
} else
*/
lora_enqueuedata(&SendBuffer, prio);
#endif #endif
#ifdef HAS_SPI #ifdef HAS_SPI
spi_enqueuedata(&SendBuffer, prio); spi_enqueuedata(&SendBuffer, prio);
#endif #endif

View File

@ -17,42 +17,31 @@ patent holder.
// Local logging tag // Local logging tag
static const char TAG[] = __FILE__; static const char TAG[] = __FILE__;
TaskHandle_t timeSyncReqTask, timeSyncAnsTask; TaskHandle_t timeSyncReqTask;
time_sync_message_t time_sync_message_t time_sync_messages[TIME_SYNC_SAMPLES] = {0},
time_sync_messages[TIME_SYNC_SAMPLES + 1] = {0}, time_sync_answers[TIME_SYNC_SAMPLES] = {0};
time_sync_answers[TIME_SYNC_SAMPLES + uint8_t time_sync_seqNo = 0;
1] = {0}; bool time_sync_pending = false;
uint8_t time_sync_seqNo = 0; // used in lorawan.cpp to store timestamp
// send time request message // send time request message
void send_Servertime_req() { void send_Servertime_req() {
// if a timesync handshake is pending then exit // if a timesync handshake is pending then exit
if ((timeSyncAnsTask) || (timeSyncReqTask)) { if (time_sync_pending) {
ESP_LOGI(TAG, "Timesync sync request already running"); ESP_LOGI(TAG, "Timeserver sync request already running");
return; return;
} else { } else {
ESP_LOGI(TAG, "Timeserver sync request started"); ESP_LOGI(TAG, "Timeserver sync request started");
time_sync_pending = true;
// clear timestamp array // clear timestamp array
for (uint8_t i = 0; i <= TIME_SYNC_SAMPLES + 1; i++) { for (uint8_t i = 0; i <= TIME_SYNC_SAMPLES + 1; i++) {
time_sync_messages[i].seconds = time_sync_answers[i].seconds = 0; time_sync_messages[i].seconds = time_sync_answers[i].seconds = 0;
time_sync_messages[i].fractions = time_sync_answers[i].fractions = 0; time_sync_messages[i].fractions = time_sync_answers[i].fractions = 0;
} }
time_sync_seqNo = 0; // kick off temporary task for timeserver handshake processing
// create temporary task for processing sync answers if not already active
if (!timeSyncAnsTask)
xTaskCreatePinnedToCore(process_Servertime_sync_ans, // task function
"timesync_ans", // name of task
2048, // stack size of task
(void *)1, // task parameter
0, // priority of the task
&timeSyncAnsTask, // task handle
1); // CPU core
// create temporary task sending sync requests
if (!timeSyncReqTask) if (!timeSyncReqTask)
xTaskCreatePinnedToCore(process_Servertime_sync_req, // task function xTaskCreatePinnedToCore(process_Servertime_sync_req, // task function
"timesync_req", // name of task "timesync_req", // name of task
@ -68,7 +57,7 @@ void send_Servertime_req() {
void recv_Servertime_ans(uint8_t val[]) { void recv_Servertime_ans(uint8_t val[]) {
// if no timesync handshake is pending then exit // if no timesync handshake is pending then exit
if (!time_sync_seqNo) if (!time_sync_pending)
return; return;
uint8_t seq_no = val[0]; uint8_t seq_no = val[0];
@ -78,65 +67,68 @@ void recv_Servertime_ans(uint8_t val[]) {
timestamp_sec = (timestamp_sec << 8) | val[i]; timestamp_sec = (timestamp_sec << 8) | val[i];
time_sync_answers[seq_no].seconds = timestamp_sec; time_sync_answers[seq_no].seconds = timestamp_sec;
} }
time_sync_answers[seq_no].fractions = val[5]; timestamp_ms = 4 * val[5];
time_sync_answers[seq_no].fractions = timestamp_ms;
ESP_LOGD(TAG, "Timeserver timestamp #%d received: time=%d.%d", seq_no, ESP_LOGD(TAG, "Timeserver answer #%d received: timestamp=%d.%03d", seq_no,
timestamp_sec, timestamp_ms); timestamp_sec, timestamp_ms);
// inform processing task // inform processing task
if (timeSyncAnsTask) if (timeSyncReqTask)
xTaskNotify(timeSyncAnsTask, seq_no, eSetBits); xTaskNotify(timeSyncReqTask, seq_no, eSetBits);
} }
// task for sending time sync requests // task for sending time sync requests
void process_Servertime_sync_req(void *taskparameter) { void process_Servertime_sync_req(void *taskparameter) {
// enqueue timestamp samples in lora sendqueue
for (uint8_t i = 1; i <= TIME_SYNC_SAMPLES; i++) {
time_sync_seqNo++;
payload.reset();
payload.addWord(TIME_SYNC_REQ_OPCODE | time_sync_seqNo << 8);
SendPayload(TIMEPORT, prio_high);
ESP_LOGD(TAG, "Timeserver request #%d sent", time_sync_seqNo);
// Wait for the next cycle
vTaskDelay(pdMS_TO_TICKS(TIME_SYNC_CYCLE * 1000));
}
payload.reset();
payload.addByte(TIME_SYNC_STOP_OPCODE);
SendPayload(TIMEPORT, prio_high); // necessary to receive last timestamp
timeSyncReqTask = NULL;
vTaskDelete(NULL); // end task
}
// task for processing a timesync handshake
void process_Servertime_sync_ans(void *taskparameter) {
uint32_t seq_no = 0, time_diff_sec = 0, time_diff_ms = 0; uint32_t seq_no = 0, time_diff_sec = 0, time_diff_ms = 0;
time_t time_to_set = 0; time_t time_to_set = 0;
float time_offset = 0.0f; float time_offset = 0.0f;
// collect incoming timestamp samples notified by rcommand // enqueue timestamp samples in lora sendqueue
for (uint8_t i = 1; i <= TIME_SYNC_SAMPLES; i++) { for (uint8_t i = 1; i <= TIME_SYNC_SAMPLES; i++) {
// wrap around seqNo 0 .. 254
time_sync_seqNo = (time_sync_seqNo >= 255) ? 0 : time_sync_seqNo + 1;
// send sync request to server
payload.reset();
payload.addWord(TIME_SYNC_REQ_OPCODE | time_sync_seqNo << 8);
SendPayload(TIMEPORT, prio_high);
ESP_LOGD(TAG, "Timeserver request #%d enqeued", time_sync_seqNo);
// send dummy packet to trigger receive answer
payload.reset();
payload.addByte(TIME_SYNC_STEP_OPCODE);
SendPayload(TIMEPORT, prio_low); // open receive slot for answer
// process answer
if ((xTaskNotifyWait(0x00, ULONG_MAX, &seq_no, if ((xTaskNotifyWait(0x00, ULONG_MAX, &seq_no,
(TIME_SYNC_CYCLE + TIME_SYNC_TIMEOUT) * 1000 / TIME_SYNC_TIMEOUT * 1000 / portTICK_PERIOD_MS) ==
portTICK_PERIOD_MS) == pdFALSE) || pdFALSE) ||
(seq_no != i)) { (seq_no != time_sync_seqNo)) {
ESP_LOGW(TAG, "Timesync handshake timeout"); ESP_LOGW(TAG, "Timeserver handshake error");
goto finish; // no valid sequence received before timeout goto finish;
} else // calculate time diff from set of collected timestamps } // no valid sequence received before timeout
{
time_diff_sec += time_sync_messages[seq_no].seconds - else { // calculate time diff from set of collected timestamps
time_sync_answers[seq_no].seconds; uint8_t k = seq_no % TIME_SYNC_SAMPLES;
time_diff_ms += 4 * (time_sync_messages[seq_no].fractions - time_diff_sec +=
time_sync_answers[seq_no].fractions); time_sync_messages[k].seconds - time_sync_answers[k].seconds;
time_diff_ms += 4 * (time_sync_messages[k].fractions -
time_sync_answers[k].fractions);
} }
} // for }
time_offset = (time_diff_sec + time_diff_ms / 1000.0) / TIME_SYNC_SAMPLES; // calculate time offset and set time if necessary
time_offset =
(time_diff_sec + time_diff_ms / 1000.0f) / (TIME_SYNC_SAMPLES * 1.0f);
ESP_LOGD(TAG, "Timesync finished, time offset=%.4f seconds", time_offset); // ESP_LOGD(TAG, "Timesync time offset=%.3f", time_offset);
ESP_LOGD(TAG, "Timesync time offset=%d.%03d", time_diff_sec / TIME_SYNC_SAMPLES,
time_diff_ms / TIME_SYNC_SAMPLES);
// check time diff and if necessary set time if (time_offset >= TIME_SYNC_TRIGGER) {
if (time_offset >= TIME_SYNC_THRESHOLD) {
// wait until top of second // wait until top of second
if (time_diff_ms > 0) { if (time_diff_ms > 0) {
@ -147,11 +139,10 @@ void process_Servertime_sync_ans(void *taskparameter) {
time_diff_sec++; time_diff_sec++;
} }
time_to_set = time_t(now() - time_diff_sec); time_to_set = time_t(now() + time_diff_sec);
ESP_LOGD(TAG, "Time to set = %d", time_to_set); ESP_LOGD(TAG, "Time to set = %d", time_to_set);
// Update system time with time read from the network // adjust system time
if (timeIsValid(time_to_set)) { if (timeIsValid(time_to_set)) {
setTime(time_to_set); setTime(time_to_set);
SyncToPPS(); SyncToPPS();
@ -166,21 +157,19 @@ void process_Servertime_sync_ans(void *taskparameter) {
finish: finish:
time_sync_seqNo = 0; time_sync_pending = false;
timeSyncAnsTask = NULL; timeSyncReqTask = NULL;
vTaskDelete(NULL); // end task vTaskDelete(NULL); // end task
} }
// called from lorawan.cpp when tine_sync_req was sent // called from lorawan.cpp immediately after time_sync_req was sent
void store_time_sync_req(time_t secs, uint32_t micros) { void store_time_sync_req(time_t secs, uint32_t micros) {
uint8_t k = time_sync_seqNo % TIME_SYNC_SAMPLES;
time_sync_messages[k].seconds = secs;
time_sync_messages[k].fractions = micros / 250; // 4ms resolution
time_sync_messages[time_sync_seqNo].seconds = secs; ESP_LOGD(TAG, "Timeserver request #%d sent at %d.%03d", time_sync_seqNo,
time_sync_messages[time_sync_seqNo].fractions = time_sync_messages[k].seconds, time_sync_messages[k].fractions);
micros / 250; // 4ms resolution
ESP_LOGD(TAG, "Timeserver request #%d was sent at %d.%d", time_sync_seqNo,
time_sync_messages[time_sync_seqNo].seconds,
time_sync_messages[time_sync_seqNo].fractions);
} }
void force_Servertime_sync(uint8_t val[]) { void force_Servertime_sync(uint8_t val[]) {