From efbe97f4321e77a379be45327f542b63ef099612 Mon Sep 17 00:00:00 2001 From: Antonin Delpeuch Date: Sat, 1 Apr 2023 22:31:40 +0200 Subject: [PATCH 1/8] Fix time offset issues in InfluxDB component. (#2278) Closes #2273 Closes #2150 --- .../jomjol_influxdb/interface_influxdb.cpp | 59 ++++--------------- 1 file changed, 10 insertions(+), 49 deletions(-) diff --git a/code/components/jomjol_influxdb/interface_influxdb.cpp b/code/components/jomjol_influxdb/interface_influxdb.cpp index 6fdc51db7..22bdd8ad9 100644 --- a/code/components/jomjol_influxdb/interface_influxdb.cpp +++ b/code/components/jomjol_influxdb/interface_influxdb.cpp @@ -46,33 +46,12 @@ void InfluxDB_V2_Publish(std::string _key, std::string _content, std::string _ti LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "InfluxDB_V2_Publish - Key: " + _key + ", Content: " + _content + ", Timestamp: " + _timestamp); - // Format: #define PREVALUE_TIME_FORMAT_OUTPUT "%Y-%m-%dT%H:%M:%S%z" - + time_t now = time(NULL); char nowTimestamp[21]; - std::string payload; - - if (_timestamp.length() > 0) - { - struct tm tm; - strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); - time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) - - struct tm * ptm; - ptm = gmtime ( &t ); - time_t utc = mktime(ptm); - utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) - - sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC - - payload = _influxDB_V2_Measurement + " " + _key + "=" + _content + " " + nowTimestamp; -// payload = _influxDB_V2_Measurement + " " + _key + "=774 " + nowTimestamp; - } - else - { - payload = _influxDB_V2_Measurement + " " + _key + "=" + _content; -// payload = _influxDB_V2_Measurement + " " + _key + "=774"; - } - + // pad with zeroes to get nanoseconds + sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); + + std::string payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); @@ -159,30 +138,12 @@ void InfluxDBPublish(std::string _key, std::string _content, std::string _timest LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "InfluxDBPublish - Key: " + _key + ", Content: " + _content + ", Timestamp: " + _timestamp); + time_t now = time(NULL); char nowTimestamp[21]; - std::string payload; - - if (_timestamp.length() > 0) - { - struct tm tm; - strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); - time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) - - struct tm * ptm; - ptm = gmtime ( &t ); - time_t utc = mktime(ptm); - utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) - - sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC - - payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; -// payload = _influxDBMeasurement + " " + _key + "=774 " + nowTimestamp; - } - else - { - payload = _influxDBMeasurement + " " + _key + "=" + _content; - } - + // pad with zeroes to get nanoseconds + sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); + + std::string payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); From e4c3596d34cc5d63e45c588325d43d65ad7f198d Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sat, 1 Apr 2023 23:06:31 +0200 Subject: [PATCH 2/8] Update interface_influxdb.cpp --- .../jomjol_influxdb/interface_influxdb.cpp | 72 ++++++++++++++++++- 1 file changed, 69 insertions(+), 3 deletions(-) diff --git a/code/components/jomjol_influxdb/interface_influxdb.cpp b/code/components/jomjol_influxdb/interface_influxdb.cpp index 22bdd8ad9..decf78f5b 100644 --- a/code/components/jomjol_influxdb/interface_influxdb.cpp +++ b/code/components/jomjol_influxdb/interface_influxdb.cpp @@ -46,12 +46,45 @@ void InfluxDB_V2_Publish(std::string _key, std::string _content, std::string _ti LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "InfluxDB_V2_Publish - Key: " + _key + ", Content: " + _content + ", Timestamp: " + _timestamp); + std::string payload; + char nowTimestamp[21]; + + if (_timestamp.length() > 0) + { + struct tm tm; + strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); + time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) + + struct tm * ptm; + ptm = gmtime ( &t ); + time_t utc = mktime(ptm); + + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); + + utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) + + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); + + + sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC + + payload = _influxDB_V2_Measurement + " " + _key + "=" + _content + " " + nowTimestamp; +// payload = _influxDB_V2_Measurement + " " + _key + "=774 " + nowTimestamp; + } + else + { + payload = _influxDB_V2_Measurement + " " + _key + "=" + _content; +// payload = _influxDB_V2_Measurement + " " + _key + "=774"; + } + +/* time_t now = time(NULL); char nowTimestamp[21]; // pad with zeroes to get nanoseconds sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); - - std::string payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; +*/ + + payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); @@ -136,14 +169,47 @@ void InfluxDBPublish(std::string _key, std::string _content, std::string _timest http_config.auth_type = HTTP_AUTH_TYPE_BASIC; } + std::string payload; + char nowTimestamp[21]; + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "InfluxDBPublish - Key: " + _key + ", Content: " + _content + ", Timestamp: " + _timestamp); + if (_timestamp.length() > 0) + { + struct tm tm; + strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); + time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) + + struct tm * ptm; + ptm = gmtime ( &t ); + time_t utc = mktime(ptm); + + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); + + utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) + + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); + + + sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC + + payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; + } + else + { + payload = _influxDB_V2_Measurement + " " + _key + "=" + _content; +// payload = _influxDB_V2_Measurement + " " + _key + "=774"; + } + + +/* time_t now = time(NULL); char nowTimestamp[21]; // pad with zeroes to get nanoseconds sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); - std::string payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; +*/ + payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); From af91af8dac6d869e430c2c7b75aedfea9832ce92 Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sat, 1 Apr 2023 23:24:02 +0200 Subject: [PATCH 3/8] Update interface_influxdb.cpp --- .../jomjol_influxdb/interface_influxdb.cpp | 36 ++++--------------- 1 file changed, 6 insertions(+), 30 deletions(-) diff --git a/code/components/jomjol_influxdb/interface_influxdb.cpp b/code/components/jomjol_influxdb/interface_influxdb.cpp index decf78f5b..28b34f00a 100644 --- a/code/components/jomjol_influxdb/interface_influxdb.cpp +++ b/code/components/jomjol_influxdb/interface_influxdb.cpp @@ -61,30 +61,18 @@ void InfluxDB_V2_Publish(std::string _key, std::string _content, std::string _ti LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); - utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) +// utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) +// LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); - LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); - - - sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC + sprintf(nowTimestamp,"%ld000000000", (long) t); // UTC payload = _influxDB_V2_Measurement + " " + _key + "=" + _content + " " + nowTimestamp; -// payload = _influxDB_V2_Measurement + " " + _key + "=774 " + nowTimestamp; } else { payload = _influxDB_V2_Measurement + " " + _key + "=" + _content; -// payload = _influxDB_V2_Measurement + " " + _key + "=774"; } -/* - time_t now = time(NULL); - char nowTimestamp[21]; - // pad with zeroes to get nanoseconds - sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); -*/ - - payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); @@ -186,30 +174,18 @@ void InfluxDBPublish(std::string _key, std::string _content, std::string _timest LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); - utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) - - LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); +// utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) +// LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); - - sprintf(nowTimestamp,"%ld000000000", (long) utc); // UTC + sprintf(nowTimestamp,"%ld000000000", (long) t); // UTC payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; } else { payload = _influxDB_V2_Measurement + " " + _key + "=" + _content; -// payload = _influxDB_V2_Measurement + " " + _key + "=774"; } - -/* - time_t now = time(NULL); - char nowTimestamp[21]; - // pad with zeroes to get nanoseconds - sprintf(nowTimestamp,"%jd000000000", (intmax_t)now); - std::string payload = _influxDBMeasurement + " " + _key + "=" + _content + " " + nowTimestamp; -*/ - payload.shrink_to_fit(); LogFile.WriteToFile(ESP_LOG_INFO, TAG, "sending line to influxdb:" + payload); From 8d7e0bcfa63f067c9c1fd2c29282a77255ee88d8 Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sun, 2 Apr 2023 09:35:04 +0200 Subject: [PATCH 4/8] Improve Logging --- .../jomjol_influxdb/interface_influxdb.cpp | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/code/components/jomjol_influxdb/interface_influxdb.cpp b/code/components/jomjol_influxdb/interface_influxdb.cpp index 28b34f00a..d5e4b2b2f 100644 --- a/code/components/jomjol_influxdb/interface_influxdb.cpp +++ b/code/components/jomjol_influxdb/interface_influxdb.cpp @@ -55,11 +55,11 @@ void InfluxDB_V2_Publish(std::string _key, std::string _content, std::string _ti strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) - struct tm * ptm; - ptm = gmtime ( &t ); - time_t utc = mktime(ptm); +// struct tm * ptm; +// ptm = gmtime ( &t ); +// time_t utc = mktime(ptm); - LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "Use handover timestamp: " + _timestamp + " converted GMT timestamp: " + std::to_string(t)); // utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) // LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); @@ -168,11 +168,11 @@ void InfluxDBPublish(std::string _key, std::string _content, std::string _timest strptime(_timestamp.c_str(), PREVALUE_TIME_FORMAT_OUTPUT, &tm); time_t t = mktime(&tm); // Time in Localtime (looks like timezone is not used by strptime) - struct tm * ptm; - ptm = gmtime ( &t ); - time_t utc = mktime(ptm); +// struct tm * ptm; +// ptm = gmtime ( &t ); +// time_t utc = mktime(ptm); - LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc before: " + std::to_string(utc) + " t: " + std::to_string(t)); + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "Use handover timestamp: " + _timestamp + " converted GMT timestamp: " + std::to_string(t)); // utc = 2*t - utc; // Take care of timezone (looks difficult, but is easy: t = t + (t - utc), weil t-utc = timezone) // LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "time conversion utc after: " + std::to_string(utc)); From 1464758af58e44324e4fd60c40d025a93435e3e0 Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sun, 2 Apr 2023 12:35:51 +0200 Subject: [PATCH 5/8] Implement TimeSync at beginning --- .../components/jomjol_time_sntp/time_sntp.cpp | 20 +++++++++++++++++++ 1 file changed, 20 insertions(+) diff --git a/code/components/jomjol_time_sntp/time_sntp.cpp b/code/components/jomjol_time_sntp/time_sntp.cpp index 78df9d5b4..05b2d7ea7 100644 --- a/code/components/jomjol_time_sntp/time_sntp.cpp +++ b/code/components/jomjol_time_sntp/time_sntp.cpp @@ -72,6 +72,20 @@ void time_sync_notification_cb(struct timeval *tv) } +bool wait_for_timesync(void) +{ + int retry = 0; + const int retry_count = 10; + while (sntp_get_sync_status() == SNTP_SYNC_STATUS_RESET && ++retry < retry_count) { + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "Waiting for system time to be set... " + std::to_string(retry) + "/" + std::to_string(retry_count)); + vTaskDelay(2000 / portTICK_PERIOD_MS); + } + if (retry >= retry_count) + return false; + return true; +} + + void setTimeZone(std::string _tzstring) { setenv("TZ", _tzstring.c_str(), 1); @@ -225,6 +239,10 @@ bool setupTime() { sntp_set_time_sync_notification_cb(time_sync_notification_cb); setTimeZone(timeZone); + if (!wait_for_timesync()) + { + LogFile.WriteToFile(ESP_LOG_INFO, TAG, "Timesync at startup failed."); + } } @@ -250,3 +268,5 @@ bool setupTime() { return true; } + + From 0eab2a5f9bbcdf1fce36618bc3ca94e4b310ab76 Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sun, 2 Apr 2023 13:42:19 +0200 Subject: [PATCH 6/8] Update time_sntp.cpp --- code/components/jomjol_time_sntp/time_sntp.cpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/code/components/jomjol_time_sntp/time_sntp.cpp b/code/components/jomjol_time_sntp/time_sntp.cpp index 05b2d7ea7..061f6bb64 100644 --- a/code/components/jomjol_time_sntp/time_sntp.cpp +++ b/code/components/jomjol_time_sntp/time_sntp.cpp @@ -74,6 +74,7 @@ void time_sync_notification_cb(struct timeval *tv) bool wait_for_timesync(void) { + sntp_restart(); int retry = 0; const int retry_count = 10; while (sntp_get_sync_status() == SNTP_SYNC_STATUS_RESET && ++retry < retry_count) { @@ -82,6 +83,8 @@ bool wait_for_timesync(void) } if (retry >= retry_count) return false; + + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "Waiting for system time successfull with " + std::to_string(retry) + "/" + std::to_string(retry_count)); return true; } From e7e4592ef7e610adfa537e5937d29b90bf62d57b Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sun, 2 Apr 2023 17:07:15 +0200 Subject: [PATCH 7/8] Update time_sntp.cpp --- code/components/jomjol_time_sntp/time_sntp.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/code/components/jomjol_time_sntp/time_sntp.cpp b/code/components/jomjol_time_sntp/time_sntp.cpp index 061f6bb64..ff6bb031c 100644 --- a/code/components/jomjol_time_sntp/time_sntp.cpp +++ b/code/components/jomjol_time_sntp/time_sntp.cpp @@ -75,6 +75,7 @@ void time_sync_notification_cb(struct timeval *tv) bool wait_for_timesync(void) { sntp_restart(); + sntp_init(); int retry = 0; const int retry_count = 10; while (sntp_get_sync_status() == SNTP_SYNC_STATUS_RESET && ++retry < retry_count) { @@ -237,11 +238,10 @@ bool setupTime() { LogFile.WriteToFile(ESP_LOG_INFO, TAG, "Configuring NTP Client..."); sntp_setoperatingmode(SNTP_OPMODE_POLL); sntp_setservername(0, timeServer.c_str()); - sntp_init(); - sntp_set_time_sync_notification_cb(time_sync_notification_cb); - setTimeZone(timeZone); + + sntp_init(); if (!wait_for_timesync()) { LogFile.WriteToFile(ESP_LOG_INFO, TAG, "Timesync at startup failed."); From 472ad00378d70e269d35f3d7a923c4646a160cf9 Mon Sep 17 00:00:00 2001 From: jomjol <30766535+jomjol@users.noreply.github.com> Date: Sun, 2 Apr 2023 17:25:53 +0200 Subject: [PATCH 8/8] Set Time After WLAN Init --- code/components/jomjol_time_sntp/time_sntp.cpp | 6 ++++-- code/components/jomjol_time_sntp/time_sntp.h | 3 +++ code/main/main.cpp | 10 ++++++++++ 3 files changed, 17 insertions(+), 2 deletions(-) diff --git a/code/components/jomjol_time_sntp/time_sntp.cpp b/code/components/jomjol_time_sntp/time_sntp.cpp index ff6bb031c..7af1c6d6d 100644 --- a/code/components/jomjol_time_sntp/time_sntp.cpp +++ b/code/components/jomjol_time_sntp/time_sntp.cpp @@ -72,10 +72,10 @@ void time_sync_notification_cb(struct timeval *tv) } -bool wait_for_timesync(void) +bool time_manual_reset_sync(void) { sntp_restart(); - sntp_init(); +// sntp_init(); int retry = 0; const int retry_count = 10; while (sntp_get_sync_status() == SNTP_SYNC_STATUS_RESET && ++retry < retry_count) { @@ -242,10 +242,12 @@ bool setupTime() { setTimeZone(timeZone); sntp_init(); +/* if (!wait_for_timesync()) { LogFile.WriteToFile(ESP_LOG_INFO, TAG, "Timesync at startup failed."); } +*/ } diff --git a/code/components/jomjol_time_sntp/time_sntp.h b/code/components/jomjol_time_sntp/time_sntp.h index 2faf324fc..c3dab062d 100644 --- a/code/components/jomjol_time_sntp/time_sntp.h +++ b/code/components/jomjol_time_sntp/time_sntp.h @@ -27,4 +27,7 @@ bool getTimeWasNotSetAtBoot(void); bool getUseNtp(void); bool setupTime(); +bool time_manual_reset_sync(void); + + #endif //TIMESNTP_H \ No newline at end of file diff --git a/code/main/main.cpp b/code/main/main.cpp index f461e7293..2889e34d5 100644 --- a/code/main/main.cpp +++ b/code/main/main.cpp @@ -337,6 +337,16 @@ extern "C" void app_main(void) ESP_LOGD(TAG, "main: sleep for: %ldms", (long) xDelay * CONFIG_FREERTOS_HZ/portTICK_PERIOD_MS); vTaskDelay( xDelay ); + + // manual reset the time + // ******************************************** + if (!time_manual_reset_sync()) + { + LogFile.WriteToFile(ESP_LOG_DEBUG, TAG, "Manual Time Sync failed during startup" ); + } + + + // Set log level for wifi component to WARN level (default: INFO; only relevant for serial console) // ******************************************** esp_log_level_set("wifi", ESP_LOG_WARN);