Merge pull request #319 from cyberman54/development

Timesync fixes
This commit is contained in:
Verkehrsrot 2019-03-17 22:05:16 +01:00 committed by GitHub
commit efc336c986
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 145 additions and 62 deletions

View File

@ -1,6 +1,9 @@
#ifndef _CONFIGMANAGER_H
#define _CONFIGMANAGER_H
#include <nvs.h>
#include <nvs_flash.h>
void eraseConfig(void);
void saveConfig(void);
void loadConfig(void);

View File

@ -7,10 +7,11 @@
#include "timekeeper.h"
#define TIME_SYNC_SAMPLES 2 // number of time requests for averaging
#define TIME_SYNC_CYCLE 2 // seconds between two time requests
#define TIME_SYNC_CYCLE 20 // seconds between two time requests
#define TIME_SYNC_TIMEOUT 120 // timeout seconds waiting for timeserver answer
#define TIME_SYNC_TRIGGER 100 // time deviation in millisec triggering a sync
#define TIME_SYNC_FRAME_LENGTH 0x06 // timeserver answer frame length
#define TIME_SYNC_FIXUP 0 // calibration millisec to fixup processing time
void send_timesync_req(void);
int recv_timesync_ans(uint8_t buf[], uint8_t buf_len);

View File

@ -1,4 +1,30 @@
[
{
"id": "46ce842a.614d5c",
"type": "ui_gauge",
"z": "449c1517.e25f4c",
"name": "Timeserver offset",
"group": "edb7cc8d.a3817",
"order": 1,
"width": 0,
"height": 0,
"gtype": "gage",
"title": "Offset gateway to server",
"label": "milliseconds",
"format": "{{value}}",
"min": 0,
"max": "2000",
"colors": [
"#00b500",
"#e6e600",
"#ca3838"
],
"seg1": "",
"seg2": "",
"x": 690,
"y": 360,
"wires": []
},
{
"id": "49e3c067.e782e",
"type": "change",
@ -48,8 +74,8 @@
"from": "",
"to": "",
"reg": false,
"x": 220,
"y": 360,
"x": 240,
"y": 420,
"wires": [
[
"84f1cda2.069e7"
@ -64,7 +90,7 @@
"topic": "+/devices/+/up",
"qos": "2",
"broker": "2a15ab6f.ab2244",
"x": 70,
"x": 110,
"y": 120,
"wires": [
[
@ -81,8 +107,8 @@
"qos": "",
"retain": "",
"broker": "2a15ab6f.ab2244",
"x": 690,
"y": 360,
"x": 730,
"y": 420,
"wires": []
},
{
@ -93,7 +119,7 @@
"property": "payload",
"action": "",
"pretty": false,
"x": 220,
"x": 260,
"y": 200,
"wires": [
[
@ -118,7 +144,7 @@
"checkall": "true",
"repair": false,
"outputs": 1,
"x": 220,
"x": 260,
"y": 120,
"wires": [
[
@ -134,12 +160,11 @@
"property": "payload",
"action": "",
"pretty": false,
"x": 540,
"y": 360,
"x": 580,
"y": 420,
"wires": [
[
"72d5e7ee.d1eba8",
"f8749724.1ff9f8"
"72d5e7ee.d1eba8"
]
]
},
@ -150,7 +175,7 @@
"name": "Decode",
"action": "",
"property": "payload.payload_raw",
"x": 380,
"x": 420,
"y": 200,
"wires": [
[
@ -165,8 +190,8 @@
"name": "Encode",
"action": "",
"property": "payload.payload_raw",
"x": 380,
"y": 360,
"x": 420,
"y": 420,
"wires": [
[
"dac8aafa.389298"
@ -179,7 +204,7 @@
"z": "449c1517.e25f4c",
"name": "LoRaWAN Timeserver",
"info": "PLEASE NOTE: There is a patent filed for the time sync algorithm used in the\ncode of this file. The shown implementation example is covered by the\nrepository's licencse, but you may not be eligible to deploy the applied\nalgorithm in applications without granted license by the patent holder.",
"x": 120,
"x": 160,
"y": 40,
"wires": []
},
@ -200,7 +225,7 @@
"checkall": "true",
"repair": false,
"outputs": 1,
"x": 550,
"x": 590,
"y": 200,
"wires": [
[
@ -213,31 +238,71 @@
"type": "function",
"z": "449c1517.e25f4c",
"name": "Generate Time Answer",
"func": "/* LoRaWAN Timeserver\n\nconstruct 6 byte timesync_answer from gateway timestamp and node's time_sync_req\n\nbyte meaning\n0 sequence number (taken from node's time_sync_req)\n1..4 current second (from epoch time 1970)\n5 1/250ths fractions of current second\n\n*/\n\nvar gateways = msg.payload.metadata.gateways;\nvar gateway_time = gateways.map(gw => new Date(gw.time));\nvar server_time = new Date(msg.payload.metadata.time);\n\ngateway_time.sort();\n\nvar gw_timestamps = gateway_time.filter(function (element) {\n return element > 0;\n});\n\nvar timestamp = gw_timestamps[0];\n\nif (timestamp < server_time) {\n\n var seconds = Math.floor(timestamp/1000);\n var fractions = (timestamp % 1000) / 4;\n var seqno = msg.payload.payload_raw[0];\n\n let buf = new ArrayBuffer(6);\n new DataView(buf).setUint8(0, seqno);\n new DataView(buf).setUint32(1, seconds);\n new DataView(buf).setUint8(5, fractions);\n\n msg.payload = new Buffer(new Uint8Array(buf));\n \n return msg;\n\n}\n\nelse\n\nreturn null;",
"outputs": 1,
"func": "/* LoRaWAN Timeserver\n\nconstruct 6 byte timesync_answer from gateway timestamp and node's time_sync_req\n\nbyte meaning\n0 sequence number (taken from node's time_sync_req)\n1..4 current second (from epoch time 1970)\n5 1/250ths fractions of current second\n\n*/\n\nfunction timecompare(a, b) {\n \n const timeA = a.time;\n const timeB = b.time;\n\n let comparison = 0;\n if (timeA > timeB) {\n comparison = 1;\n } else if (timeA < timeB) {\n comparison = -1;\n }\n return comparison;\n}\n\nlet confidence = 2000; // max millisecond diff gateway time to server time\n\nvar gateways = msg.payload.metadata.gateways;\nvar gateway_time = gateways.map(gw => {\n return {\n time: new Date(gw.time),\n eui: gw.gtw_id,\n }\n });\nvar server_time = new Date(msg.payload.metadata.time);\n\n// validate all gateway timestamps against lorawan server_time (which is assumed to be recent)\nvar gw_timestamps = gateway_time.filter(function (element) {\n return ((element.time > (server_time - confidence) && element.time <= server_time));\n});\n\n// if no timestamp left, we have no valid one and exit\nif (gw_timestamps.length === 0) return null;\n\n// sort time array in ascending order to find most recent timestamp for time answer\ngw_timestamps.sort(timecompare);\n\nvar timestamp = gw_timestamps[0].time;\nvar eui = gw_timestamps[0].eui;\nvar offset = server_time - timestamp;\n\nvar seconds = Math.floor(timestamp/1000);\nvar fractions = (timestamp % 1000) / 4;\nvar seqno = msg.payload.payload_raw[0];\n\nlet buf = new ArrayBuffer(6);\nnew DataView(buf).setUint8(0, seqno);\nnew DataView(buf).setUint32(1, seconds);\nnew DataView(buf).setUint8(5, fractions);\n\nmsg.payload = new Buffer(new Uint8Array(buf));\nvar infoMsg = { payload: eui };\nvar offsetMsg = { payload: offset };\n\nreturn [infoMsg, msg, offsetMsg];",
"outputs": 3,
"noerr": 0,
"x": 420,
"y": 280,
"y": 300,
"wires": [
[
"37722d4b.08e3c2",
"8712a5ac.ed18e8"
],
[
"49e3c067.e782e"
],
[
"46ce842a.614d5c"
]
],
"outputLabels": [
"gw_eui",
"time_sync_ans",
"offset_ms"
]
},
{
"id": "f8749724.1ff9f8",
"id": "37722d4b.08e3c2",
"type": "debug",
"z": "449c1517.e25f4c",
"name": "time_sync_ans",
"active": false,
"tosidebar": true,
"name": "Timeserver Gw",
"active": true,
"tosidebar": false,
"console": false,
"tostatus": true,
"complete": "payload",
"x": 720,
"y": 280,
"x": 700,
"y": 260,
"wires": [],
"icon": "node-red/bridge.png"
},
{
"id": "8712a5ac.ed18e8",
"type": "ui_text",
"z": "449c1517.e25f4c",
"group": "edb7cc8d.a3817",
"order": 0,
"width": 0,
"height": 0,
"name": "Timeserver",
"label": "Recent timeserver was:",
"format": "{{msg.payload}}",
"layout": "col-center",
"x": 710,
"y": 320,
"wires": []
},
{
"id": "edb7cc8d.a3817",
"type": "ui_group",
"z": "",
"name": "Timeserver",
"tab": "d525a5d.0832858",
"order": 4,
"disp": true,
"width": "6",
"collapse": false
},
{
"id": "2a15ab6f.ab2244",
"type": "mqtt-broker",
@ -260,5 +325,15 @@
"willTopic": "",
"willQos": "0",
"willPayload": ""
},
{
"id": "d525a5d.0832858",
"type": "ui_tab",
"z": "",
"name": "Timeserver",
"icon": "sync",
"order": 3,
"disabled": false,
"hidden": false
}
]

View File

@ -1,8 +1,6 @@
/* configmanager persists runtime configuration using NVRAM of ESP32*/
#include "globals.h"
#include <nvs.h>
#include <nvs_flash.h>
// Local logging tag
static const char TAG[] = "flash";
@ -84,7 +82,8 @@ void saveConfig() {
if (nvs_get_blob(my_handle, "bsecstate", bsecstate_buffer,
&required_size) != ESP_OK ||
memcmp(bsecstate_buffer, cfg.bsecstate, BSEC_MAX_STATE_BLOB_SIZE + 1) != 0)
memcmp(bsecstate_buffer, cfg.bsecstate, BSEC_MAX_STATE_BLOB_SIZE + 1) !=
0)
nvs_set_blob(my_handle, "bsecstate", cfg.bsecstate,
BSEC_MAX_STATE_BLOB_SIZE + 1);
@ -215,8 +214,7 @@ void loadConfig() {
if (nvs_get_blob(my_handle, "bsecstate", NULL, &required_size) == ESP_OK) {
nvs_get_blob(my_handle, "bsecstate", cfg.bsecstate, &required_size);
ESP_LOGI(TAG, "bsecstate = %d",
cfg.bsecstate[BSEC_MAX_STATE_BLOB_SIZE]);
ESP_LOGI(TAG, "bsecstate = %d", cfg.bsecstate[BSEC_MAX_STATE_BLOB_SIZE]);
};
if (nvs_get_i8(my_handle, "lorasf", &flash8) == ESP_OK) {
@ -333,9 +331,9 @@ void loadConfig() {
if (nvs_get_i8(my_handle, "payloadmask", &flash8) == ESP_OK) {
cfg.payloadmask = flash8;
ESP_LOGI(TAG, "payloadmask = %d", flash8);
ESP_LOGI(TAG, "payloadmask = %hhu", flash8);
} else {
ESP_LOGI(TAG, "payloadmask set to default %d", cfg.payloadmask);
ESP_LOGI(TAG, "payloadmask set to default %hhu", cfg.payloadmask);
saveConfig();
}

View File

@ -490,6 +490,9 @@ void user_request_network_time_callback(void *pVoidUserUTCTime,
// Update system time with time read from the network
if (timeIsValid(*pUserUTCTime)) {
setTime(*pUserUTCTime);
#ifdef HAS_RTC
set_rtctime(*pUserUTCTime); // calibrate RTC if we have one
#endif
timeSource = _lora;
timesyncer.attach(TIME_SYNC_INTERVAL * 60, timeSync); // regular repeat
ESP_LOGI(TAG, "Received recent time from LoRa");

View File

@ -20,8 +20,8 @@ static const char TAG[] = __FILE__;
TaskHandle_t timeSyncReqTask;
static uint8_t time_sync_seqNo{};
static bool lora_time_sync_pending{false};
static uint8_t time_sync_seqNo = 0;
static bool lora_time_sync_pending = false;
typedef std::chrono::system_clock myClock;
typedef myClock::time_point myClock_timepoint;
@ -44,8 +44,8 @@ void send_timesync_req() {
lora_time_sync_pending = true;
// initialize timestamp array
for (uint8_t i{}; i < TIME_SYNC_SAMPLES; i++)
// clear timestamp array
for (uint8_t i = 0; i < TIME_SYNC_SAMPLES; i++)
time_sync_tx[i] = time_sync_rx[i] = myClock_timepoint();
// kick off temporary task for timeserver handshake processing
@ -63,12 +63,11 @@ void send_timesync_req() {
// task for sending time sync requests
void process_timesync_req(void *taskparameter) {
uint8_t k{};
uint32_t seq_no = 0, time_to_set_us, time_to_set_ms;
uint16_t time_to_set_fraction_msec;
uint32_t seq_no{}, time_to_set_us;
long long int time_to_set_ms;
uint8_t k = 0, i = 0;
time_t time_to_set;
auto time_offset{myClock_msecTick::zero()};
auto time_offset = myClock_msecTick::zero();
// wait until we are joined
while (!LMIC.devaddr) {
@ -76,7 +75,7 @@ void process_timesync_req(void *taskparameter) {
}
// enqueue timestamp samples in lora sendqueue
for (uint8_t i{}; i < TIME_SYNC_SAMPLES; i++) {
for (uint8_t i = 0; i < TIME_SYNC_SAMPLES; i++) {
// wrap around seqNo 0 .. 254
time_sync_seqNo = (time_sync_seqNo >= 255) ? 0 : time_sync_seqNo + 1;
@ -122,27 +121,28 @@ void process_timesync_req(void *taskparameter) {
ESP_LOGD(TAG, "[%0.3f] avg time diff: %0.3f sec", millis() / 1000.0,
myClock_secTick(time_offset).count());
// calculate absolute time with millisecond precision
time_to_set_ms = (long long)now(time_to_set_us) * 1000LL +
time_to_set_us / 1000LL + time_offset.count();
// 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()));
// apply calibration factor for processing time
time_offset += milliseconds(TIME_SYNC_FIXUP);
// convert to seconds
time_to_set = (time_t)(time_to_set_ms / 1000LL);
time_to_set = static_cast<time_t>(myClock_secTick(time_offset).count());
// calculate fraction milliseconds
time_to_set_fraction_msec = (uint16_t)(time_to_set_ms % 1000LL);
time_to_set_fraction_msec = static_cast<uint16_t>(time_offset.count() % 1000);
ESP_LOGD(TAG, "[%0.3f] Calculated UTC epoch time: %d.%03d sec",
millis() / 1000.0, time_to_set, time_to_set_fraction_msec);
// adjust system time
if (timeIsValid(time_to_set)) {
if (abs(time_offset.count()) >=
TIME_SYNC_TRIGGER) { // milliseconds threshold
// wait until top of second
ESP_LOGD(TAG, "[%0.3f] waiting %d ms", millis() / 1000.0,
1000 - time_to_set_fraction_msec);
vTaskDelay(pdMS_TO_TICKS(1000 - time_to_set_fraction_msec));
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));
// sync timer pps to top of second
if (ppsIRQ) {
@ -150,9 +150,12 @@ void process_timesync_req(void *taskparameter) {
CLOCKIRQ(); // fire clock pps interrupt
}
setTime(time_to_set + 1);
timeSource = _lora;
setTime(++time_to_set); // +1 sec after waiting for top of seceond
#ifdef HAS_RTC
set_rtctime(time_to_set); // calibrate RTC if we have one
#endif
timeSource = _lora;
timesyncer.attach(TIME_SYNC_INTERVAL * 60,
timeSync); // set to regular repeat
ESP_LOGI(TAG, "[%0.3f] Timesync finished, time adjusted by %.3f sec",
@ -170,15 +173,15 @@ finish:
}
// called from lorawan.cpp after time_sync_req was sent
void store_time_sync_req(uint32_t t_millisec) {
void store_time_sync_req(uint32_t t_txEnd_ms) {
uint8_t k{time_sync_seqNo % TIME_SYNC_SAMPLES};
uint8_t k = time_sync_seqNo % TIME_SYNC_SAMPLES;
time_sync_tx[k] += milliseconds(t_millisec);
time_sync_tx[k] += milliseconds(t_txEnd_ms);
ESP_LOGD(TAG, "[%0.3f] Timesync request #%d sent at %d.%03d",
millis() / 1000.0, time_sync_seqNo, t_millisec / 1000,
t_millisec % 1000);
millis() / 1000.0, time_sync_seqNo, t_txEnd_ms / 1000,
t_txEnd_ms % 1000);
}
// process timeserver timestamp answer, called from lorawan.cpp
@ -188,16 +191,16 @@ int recv_timesync_ans(uint8_t buf[], uint8_t buf_len) {
if ((!lora_time_sync_pending) || (buf_len != TIME_SYNC_FRAME_LENGTH))
return 0; // failure
uint8_t seq_no{buf[0]}, k{seq_no % TIME_SYNC_SAMPLES};
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;
// get the timeserver time.
// The first 4 bytes contain the UTC seconds since unix epoch.
// Octet order is little endian. Casts are necessary, because buf is an array
// Octet order is big endian. Casts are necessary, because buf is an array
// of single byte values, and they might overflow when shifted
timestamp_sec = ((uint32_t)buf[1]) | (((uint32_t)buf[2]) << 8) |
(((uint32_t)buf[3]) << 16) | (((uint32_t)buf[4]) << 24);
timestamp_sec = ((uint32_t)buf[4]) | (((uint32_t)buf[3]) << 8) |
(((uint32_t)buf[2]) << 16) | (((uint32_t)buf[1]) << 24);
// The 5th byte contains the fractional seconds in 2^-8 second steps
timestamp_msec = 4 * buf[5];