reworked lora appserver timesync logic (part 2)

This commit is contained in:
Klaus K Wilting 2020-03-03 16:38:29 +01:00
parent 1516d71018
commit c17bfa02af
2 changed files with 54 additions and 49 deletions

View File

@ -8,8 +8,10 @@
//#define TIME_SYNC_TRIGGER 100 // threshold for time sync [milliseconds] //#define TIME_SYNC_TRIGGER 100 // threshold for time sync [milliseconds]
#define TIME_SYNC_FRAME_LENGTH 0x07 // timeserver answer frame length [bytes] #define TIME_SYNC_FRAME_LENGTH 0x07 // timeserver answer frame length [bytes]
#define TIME_SYNC_FIXUP 4 // calibration to fixup processing time [milliseconds] #define TIME_SYNC_FIXUP 16 // empirical calibration to fixup processing time [milliseconds]
#define TIMEREQUEST_MAX_SEQNO 0xf0 // threshold for wrap around seqno #define TIMEREQUEST_MAX_SEQNO 0xfe // threshold for wrap around seqno
#define TIMEREQUEST_FINISH \
(TIMEREQUEST_MAX_SEQNO + 1) // marker for end of timesync handshake
enum timesync_t { enum timesync_t {
timesync_tx, timesync_tx,

View File

@ -19,6 +19,7 @@ static const char TAG[] = __FILE__;
TaskHandle_t timeSyncReqTask = NULL; TaskHandle_t timeSyncReqTask = NULL;
static uint8_t time_sync_seqNo = (uint8_t)random(TIMEREQUEST_MAX_SEQNO); static uint8_t time_sync_seqNo = (uint8_t)random(TIMEREQUEST_MAX_SEQNO);
static uint8_t sample_idx = 0;
static bool timeSyncPending = false; static bool timeSyncPending = false;
static uint32_t timesync_timestamp[TIME_SYNC_SAMPLES][no_of_timestamps] = {0}; static uint32_t timesync_timestamp[TIME_SYNC_SAMPLES][no_of_timestamps] = {0};
@ -38,8 +39,12 @@ void send_timesync_req() {
// task for sending time sync requests // task for sending time sync requests
void process_timesync_req(void *taskparameter) { void process_timesync_req(void *taskparameter) {
uint8_t i; uint32_t rcv_seq_no = TIMEREQUEST_FINISH, time_offset_ms;
uint32_t seq_no, time_offset_ms;
// this task is an endless loop, waiting in blocked mode, until it is
// unblocked by send_timesync_req(). It then waits to be notified from
// recv_timesync_ans(), which is called from RX callback in lorawan.cpp, each
// time a timestamp from timeserver arrived.
// --- asnychronous part: generate and collect timestamps from gateway --- // --- asnychronous part: generate and collect timestamps from gateway ---
@ -48,22 +53,23 @@ void process_timesync_req(void *taskparameter) {
// wait for kickoff // wait for kickoff
ulTaskNotifyTake(pdFALSE, portMAX_DELAY); ulTaskNotifyTake(pdFALSE, portMAX_DELAY);
timeSyncPending = true; timeSyncPending = true;
time_offset_ms = 0;
// wait until we are joined if we are not // wait until we are joined if we are not
while (!LMIC.devaddr) { while (!LMIC.devaddr) {
vTaskDelay(pdMS_TO_TICKS(3000)); vTaskDelay(pdMS_TO_TICKS(5000));
} }
// generate and collect timestamp samples // trigger and collect timestamp samples
for (i = 0; i < TIME_SYNC_SAMPLES; i++) { for (uint8_t i = 0; i < TIME_SYNC_SAMPLES; i++) {
// send sync request to server // send timesync request to timeserver
payload.reset(); payload.reset();
payload.addByte(time_sync_seqNo); payload.addByte(time_sync_seqNo);
SendPayload(TIMEPORT, prio_high); SendPayload(TIMEPORT, prio_high);
// wait for a valid timestamp from recv_timesync_ans() // wait until recv_timesync_ans() signals a timestamp was received
while (seq_no != time_sync_seqNo) { while (rcv_seq_no != time_sync_seqNo) {
if (xTaskNotifyWait(0x00, ULONG_MAX, &seq_no, if (xTaskNotifyWait(0x00, ULONG_MAX, &rcv_seq_no,
pdMS_TO_TICKS(TIME_SYNC_TIMEOUT * 1000)) == pdMS_TO_TICKS(TIME_SYNC_TIMEOUT * 1000)) ==
pdFALSE) { pdFALSE) {
ESP_LOGW(TAG, "[%0.3f] Timesync handshake error: timeout", ESP_LOGW(TAG, "[%0.3f] Timesync handshake error: timeout",
@ -72,21 +78,30 @@ void process_timesync_req(void *taskparameter) {
} }
} }
// wrap around seqNo, keeping it in time port range ESP_LOGD(TAG, "sample_idx = %d", sample_idx);
// calculate time diff from collected timestamps
time_offset_ms += timesync_timestamp[sample_idx][timesync_rx] -
timesync_timestamp[sample_idx][timesync_tx];
// increment and maybe wrap around seqNo, keeping it in time port range
time_sync_seqNo++; time_sync_seqNo++;
if (time_sync_seqNo > TIMEREQUEST_MAX_SEQNO) { if (time_sync_seqNo > TIMEREQUEST_MAX_SEQNO) {
time_sync_seqNo = 0; time_sync_seqNo = 0;
} }
if (i < TIME_SYNC_SAMPLES - 1) { // increment index for timestamp array
// wait until next cycle sample_idx++;
// if last cycle, send finish char for closing timesync handshake,
// else wait until time has come for next cycle
if (i < TIME_SYNC_SAMPLES - 1) { // wait for next cycle
vTaskDelay(pdMS_TO_TICKS(TIME_SYNC_CYCLE * 1000)); vTaskDelay(pdMS_TO_TICKS(TIME_SYNC_CYCLE * 1000));
} else { // before sending last time sample... } else { // finish timesync handshake
// ...send flush to open a receive window for last time_sync_answer
payload.reset(); payload.reset();
payload.addByte(0x99); payload.addByte(TIMEREQUEST_FINISH);
SendPayload(RCMDPORT, prio_high); SendPayload(RCMDPORT, prio_high);
// ...send a alive open a receive window for last time_sync_answer // open a receive window to get last time_sync_answer instantly
LMIC_sendAlive(); LMIC_sendAlive();
} }
@ -97,45 +112,36 @@ void process_timesync_req(void *taskparameter) {
// mask application irq to ensure accurate timing // mask application irq to ensure accurate timing
mask_user_IRQ(); mask_user_IRQ();
time_offset_ms = 0; // average time offset over the summed up difference
// + add msec from recent gateway time, found with last sample_idx
for (i = 0; i < TIME_SYNC_SAMPLES; i++) { // + apply a compensation constant TIME_SYNC_FIXUP for processing time
// calculate time diff from collected timestamps and apply
// a compensation constant TIME_SYNC_FIXUP for processing time
time_offset_ms += timesync_timestamp[i][timesync_rx] -
timesync_timestamp[i][timesync_tx] + TIME_SYNC_FIXUP;
}
// decrement i for subscription to latest element in timestamp array
i--;
// average time offset over all collected diffs and add gateway time msec
time_offset_ms /= TIME_SYNC_SAMPLES; time_offset_ms /= TIME_SYNC_SAMPLES;
time_offset_ms += timesync_timestamp[i][gwtime_msec]; time_offset_ms +=
timesync_timestamp[sample_idx - 1][gwtime_msec] + TIME_SYNC_FIXUP;
// calculate absolute time in UTC epoch: take latest time received from // calculate absolute time in UTC epoch: take latest time received from
// gateway, convert to whole seconds, round to ceil, add fraction seconds // gateway, convert to whole seconds, round to ceil, add fraction seconds
setMyTime(timesync_timestamp[sample_idx - 1][gwtime_sec] +
setMyTime(timesync_timestamp[i][gwtime_sec] + time_offset_ms / 1000, time_offset_ms / 1000,
time_offset_ms % 1000, _lora); time_offset_ms % 1000, _lora);
finish:
// end of time critical section: release app irq lock // end of time critical section: release app irq lock
timeSyncPending = false;
unmask_user_IRQ(); unmask_user_IRQ();
finish:
timeSyncPending = false;
} // infinite while(1) } // infinite while(1)
} }
// called from lorawan.cpp // called from lorawan.cpp
void store_timestamp(uint32_t timestamp, timesync_t timestamp_type) { void store_timestamp(uint32_t timestamp, timesync_t timestamp_type) {
uint8_t seq = time_sync_seqNo % TIME_SYNC_SAMPLES; ESP_LOGD(TAG, "[%0.3f] seq#%d[%d]: timestamp(t%d)=%d",
timesync_timestamp[seq][timestamp_type] = timestamp; millis() / 1000.0, time_sync_seqNo, sample_idx, timestamp_type,
timestamp);
ESP_LOGD(TAG, "[%0.3f] Timesync seq#%d: timestamp(%d) %d stored", timesync_timestamp[sample_idx][timestamp_type] = timestamp;
millis() / 1000.0, seq, timestamp_type, timestamp);
} }
// process timeserver timestamp answer, called by myRxCallback() in lorawan.cpp // process timeserver timestamp answer, called by myRxCallback() in lorawan.cpp
@ -155,7 +161,7 @@ int recv_timesync_ans(const uint8_t buf[], const uint8_t buf_len) {
if (!timeSyncPending) if (!timeSyncPending)
return 0; // failure return 0; // failure
// extract 1 byte timerequest sequence number from buffer // extract 1 byte timerequest sequence number from payload
uint8_t seq_no = buf[0]; uint8_t seq_no = buf[0];
buf++; buf++;
@ -172,16 +178,14 @@ int recv_timesync_ans(const uint8_t buf[], const uint8_t buf_len) {
else { // we received a probably valid time frame else { // we received a probably valid time frame
uint8_t k = seq_no % TIME_SYNC_SAMPLES;
// pointers to 4 bytes containing UTC seconds since unix epoch, msb // pointers to 4 bytes containing UTC seconds since unix epoch, msb
uint32_t timestamp_sec, *timestamp_ptr; uint32_t timestamp_sec, *timestamp_ptr;
// extract 1 byte timezone from buffer (one step being 15min * 60s = 900s) // extract 1 byte timezone from payload (one step being 15min * 60s = 900s)
// uint32_t timezone_sec = buf[0] * 900; // for future use // uint32_t timezone_sec = buf[0] * 900; // for future use
buf++; buf++;
// extract 4 bytes timestamp from buffer // extract 4 bytes timestamp from payload
// and convert it to uint32_t, octet order is big endian // and convert it to uint32_t, octet order is big endian
timestamp_ptr = (uint32_t *)buf; timestamp_ptr = (uint32_t *)buf;
// swap byte order from msb to lsb, note: this is platform dependent // swap byte order from msb to lsb, note: this is platform dependent
@ -195,9 +199,8 @@ int recv_timesync_ans(const uint8_t buf[], const uint8_t buf_len) {
// we guess timepoint is recent if it is newer than code compile date // we guess timepoint is recent if it is newer than code compile date
if (timeIsValid(t)) { if (timeIsValid(t)) {
ESP_LOGD(TAG, "[%0.3f] Timesync request #%d of %d rcvd at %0.3f", ESP_LOGD(TAG, "[%0.3f] Timesync request seq#%d rcvd at %0.3f",
millis() / 1000.0, k + 1, TIME_SYNC_SAMPLES, millis() / 1000.0, seq_no, osticks2ms(os_getTime()) / 1000.0);
osticks2ms(os_getTime()) / 1000.0);
// store time received from gateway // store time received from gateway
store_timestamp(timestamp_sec, gwtime_sec); store_timestamp(timestamp_sec, gwtime_sec);