Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Round 1 begins before NTP is called (wrong timestamp) #2287

Closed
TopGoalVl opened this issue Apr 3, 2023 · 2 comments
Closed

Round 1 begins before NTP is called (wrong timestamp) #2287

TopGoalVl opened this issue Apr 3, 2023 · 2 comments
Labels
bug Something isn't working

Comments

@TopGoalVl
Copy link

The Problem

After update to V 15.1.1, the first Data entry has a wrong Timestamp (see data- / message log). After changing the time settings (CET / CEST) for Berlin / Germany (long notation) nothing improved. The problem can be reproduced.

In my case, the time is only displayed correctly after synchronization with the NTP server (de.pool.ntp.org). If data is created beforehand with a timestamp, the time will be wrong.

Version

Release: v15.1.1 (Commit: 03c84a1+)

Logfile

'''

Data log before update: 
2023-04-03T18:05:48+0200,main,0470.11519,,440.114990,,0.05370,Rate too high - Read: 470.11519 - Pre: 440.11499 - Rate: 30.00020,0.0,4.0,7.0,0.0,1.0,1.5,5.3,1.9
2023-04-03T18:10:39+0200,main,0470.11519,,440.115204,,0.05370,Rate too high - Read: 470.11519 - Pre: 440.11520 - Rate: 29.99999,0.0,4.0,7.0,0.0,1.0,1.5,5.3,1.9
Data log after Update:
2023-04-03T21:13:10+0200,main,0440.11519,440.11520,440.11520,0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.0,1.5,5.3,1.9 <=== Wrong time after update to V 15.1.1
2023-04-03T18:21:46+0200,main,0440.11519,440.11520,440.11520,0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.0,1.5,5.3,1.9
2023-04-03T18:26:37+0200,main,0440.11519,440.11520,440.11520,0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.0,1.5,5.3,1.9 

Message log last records before update:
[16d17h30m29s] 2023-04-03T18:06:35 <ERR> [POSTPROC] main: Raw: 0470.11519, Value: , Status: Rate too high - Read: 470.11519 - Pre: 440.11499 - Rate: 30.00020
[16d17h35m23s] 2023-04-03T18:11:29 <ERR> [POSTPROC] main: Raw: 0470.11519, Value: , Status: Rate too high - Read: 470.11519 - Pre: 440.11520 - Rate: 29.99999
[16d17h39m07s] 2023-04-03T18:15:13 <WRN> [OTA] Reboot in 5sec <=== Correct Time CEST +0200

Message log after update:
[0d00h00m04s] 2023-04-03T22:04:28 <INF> [SNTP] TimeServer: de.pool.ntp.org
[0d00h00m04s] 2023-04-03T22:04:28 <INF> [SNTP] Configuring NTP Client...
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [MAIN] =================================================
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [MAIN] ==================== Start ======================
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [MAIN] =================================================
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [SDCARD] Basic R/W check started...
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [SDCARD] Basic R/W check successful
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line '[MakeImage]' to '[TakeImage]'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogImageLocation = /log/source' to 'RawImagesLocation = /log/source'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogfileRetentionInDays = 32' to 'RawImagesRetention = 32'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line ';Demo = false' to 'Demo = false'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogImageLocation = /log/digit' to 'ROIImagesLocation = /log/digit'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogfileRetentionInDays = 32' to 'ROIImagesRetention = 32'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogImageLocation = /log/analog' to 'ROIImagesLocation = /log/analog'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogfileRetentionInDays = 32' to 'ROIImagesRetention = 32'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'SetRetainFlag = true' to 'RetainMessages = true'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line ';HomeassistantDiscovery = false' to 'HomeassistantDiscovery = false'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'Intervall = 4.85' to 'Interval = 4.85'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'DataLogRetentionInDays = 32' to 'DataFilesRetention = 32'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'Logfile = 2' to 'LogLevel = 2'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line 'LogfileRetentionInDays = 16' to 'LogfilesRetention = 16'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line ';AutoAdjustSummertime = false' to ';;UNUSED_PARAMETER = false'
[0d00h00m04s] 2023-04-03T19:12:52 <ERR> [HELPER] Migrated Configfile line ';RSSIThreashold = ' to ';RSSIThreshold = '
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [MAIN] Config file migrated. Saved backup to /sdcard/config/config.bak
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [SNTP] TimeServer: de.pool.ntp.org
[0d00h00m04s] 2023-04-03T19:12:52 <INF> [SNTP] Configuring NTP Client...
[0d00h00m04s] 2023-04-03T21:12:52 <INF> [SNTP] Time zone set to CET-1CEST,M3.5.0,M10.5.0/3
[0d00h00m04s] 2023-04-03T21:12:52 <INF> [SNTP] Time is already set: 2023-04-03 21:12:52
[0d00h00m04s] 2023-04-03T21:12:53 <INF> [MAIN] CPU frequency: 160 MHz
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [SDCARD] Folder/file presence check started...
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [SDCARD] Folder/file presence check successful
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [MAIN] Tag: 'v15.1.1', Release: v15.1.1 (Commit: 03c84a1+), Date/Time: 2023-03-23 20:40, Web UI: Release: v15.1.1 (Commit: 03c84a1+)
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [MAIN] Reset reason: Via esp_restart
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [WLANINI] SSID: NetBridgeAp-104A
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [WLANINI] Password: XXXXXXXX
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [WLANINI] Hostname: LeuVoShWz6
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [MAIN] WLAN config loaded, init WIFI...
[0d00h00m05s] 2023-04-03T21:12:53 <INF> [WIFI] Automatic interface config --> Use DHCP service
[0d00h00m05s] 2023-04-03T21:12:54 <INF> [WIFI] Set hostname to: LeuVoShWz6
[0d00h00m05s] 2023-04-03T21:12:54 <INF> [WIFI] Init successful
[0d00h00m07s] 2023-04-03T21:12:56 <INF> [MAIN] PSRAM size: 8388608 byte (8MB / 64MBit)
[0d00h00m08s] 2023-04-03T21:12:56 <INF> [MAIN] Total heap: 4175378 byte
[0d00h00m08s] 2023-04-03T21:12:56 <INF> [MAIN] Camera info: PID: 0x26, VER: 0x42, MIDL: 0x7f, MIDH: 0xa2
[0d00h00m08s] 2023-04-03T21:12:56 <INF> [MAIN] Device info: CPU cores: 2, Chip revision: 1
[0d00h00m08s] 2023-04-03T21:12:56 <INF> [MAIN] SD card info: Name: EB1QT, Capacity: 30528MB, Free: 28747MB
[0d00h00m10s] 2023-04-03T21:12:58 <INF> [MAIN] Initialization completed successfully! Starting flow task ...
[0d00h00m10s] 2023-04-03T21:12:58 <INF> [WIFI] Connected to: NetBridgeAp-104A, RSSI: -47
[0d00h00m11s] 2023-04-03T21:12:59 <INF> [WIFI] Assigned IP: 192.168.188.6
[0d00h00m12s] 2023-04-03T21:13:00 <INF> [LOGFILE] Set log level to WARNING

'''

Expected Behavior

No response

Screenshots

No response

Additional Context

Current Config.ini
[System]
TimeZone = CET-1CEST,M3.5.0,M10.5.0/3
TimeServer = de.pool.ntp.org

Default Setup watermeter SD-Card config.ini
Warsaw, Poland CET-1CEST,M3.5.0,M10.5.0/3

Correction to:
Berlin, Germany CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00
@TopGoalVl TopGoalVl added the bug Something isn't working label Apr 3, 2023
@TopGoalVl
Copy link
Author

Addendum:
I forgot to transfer a data and message log.
See the log marker: <=== #1 Round 1 begins, before NTP is called

'''
Datalog after changed TZ-data to CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00

2023-04-03T20:52:07+0200,main,0440.14046,440.14046,440.14046,0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.2,3.9,0.5,4.6
2023-04-03T11:32:39+0200,main,0440.14046,440.14046,440.14046,-0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.3,3.9,0.5,4.6 <=== #1 Round 1 begins, before NTP is called
2023-04-03T21:00:24+0200,main,0440.14046,440.14046,440.14046,0.000000,0.00000,no error,0.0,4.0,3.8,0.0,1.3,3.9,0.5,4.6

Messagelog after changed TZ-data to CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00

[0d02h38m30s] 2023-04-03T20:55:03 [OTA] Reboot in 5sec
[0d00h00m04s] 2023-04-03T09:32:22 [MAIN] =================================================
[0d00h00m04s] 2023-04-03T09:32:22 [MAIN] ==================== Start ======================
[0d00h00m04s] 2023-04-03T09:32:22 [MAIN] =================================================
[0d00h00m04s] 2023-04-03T09:32:22 [SDCARD] Basic R/W check started...
[0d00h00m04s] 2023-04-03T09:32:22 [SDCARD] Basic R/W check successful
[0d00h00m04s] 2023-04-03T09:32:22 [SNTP] TimeServer: de.pool.ntp.org
[0d00h00m04s] 2023-04-03T09:32:22 [SNTP] Configuring NTP Client...
[0d00h00m04s] 2023-04-03T11:32:22 [SNTP] Time zone set to CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00
[0d00h00m04s] 2023-04-03T11:32:22 [SNTP] Time is already set: 2023-04-03 11:32:22
[0d00h00m04s] 2023-04-03T11:32:22 [MAIN] CPU frequency: 160 MHz
[0d00h00m05s] 2023-04-03T11:32:22 [SDCARD] Folder/file presence check started...
[0d00h00m05s] 2023-04-03T11:32:22 [SDCARD] Folder/file presence check successful
[0d00h00m05s] 2023-04-03T11:32:22 [MAIN] Tag: 'v15.1.1', Release: v15.1.1 (Commit: 03c84a1+), Date/Time: 2023-03-23 20:40, Web UI: Release: v15.1.1 (Commit: 03c84a1+)
[0d00h00m05s] 2023-04-03T11:32:22 [MAIN] Reset reason: Via esp_restart
[0d00h00m05s] 2023-04-03T11:32:22 [WLANINI] SSID: NetBridgeAp-104A
[0d00h00m05s] 2023-04-03T11:32:22 [WLANINI] Password: XXXXXXXX
[0d00h00m05s] 2023-04-03T11:32:22 [WLANINI] Hostname: LeuVoShWz6
[0d00h00m05s] 2023-04-03T11:32:22 [MAIN] WLAN config loaded, init WIFI...
[0d00h00m05s] 2023-04-03T11:32:22 [WIFI] Automatic interface config --> Use DHCP service
[0d00h00m05s] 2023-04-03T11:32:23 [WIFI] Set hostname to: LeuVoShWz6
[0d00h00m05s] 2023-04-03T11:32:23 [WIFI] Init successful
[0d00h00m07s] 2023-04-03T11:32:25 [MAIN] PSRAM size: 8388608 byte (8MB / 64MBit)
[0d00h00m07s] 2023-04-03T11:32:25 [MAIN] Total heap: 4175198 byte
[0d00h00m07s] 2023-04-03T11:32:25 [MAIN] Camera info: PID: 0x26, VER: 0x42, MIDL: 0x7f, MIDH: 0xa2
[0d00h00m07s] 2023-04-03T11:32:25 [MAIN] Device info: CPU cores: 2, Chip revision: 1
[0d00h00m07s] 2023-04-03T11:32:25 [MAIN] SD card info: Name: EB1QT, Capacity: 30528MB, Free: 28741MB
[0d00h00m09s] 2023-04-03T11:32:27 [WIFI] Connected to: NetBridgeAp-104A, RSSI: -45
[0d00h00m09s] 2023-04-03T11:32:27 [MAIN] Initialization completed successfully! Starting flow task ...
[0d00h00m10s] 2023-04-03T11:32:27 [WIFI] Assigned IP: 192.168.188.6
[0d00h00m12s] 2023-04-03T11:32:29 [LOGFILE] Set log level to INFO
[0d00h00m12s] 2023-04-03T11:32:29 [MQTT IF] Init
[0d00h00m12s] 2023-04-03T11:32:29 [MQTT IF] Client started, waiting for established connection...
[0d00h00m12s] 2023-04-03T11:32:30 [TFLITE SERVER] Round #1 started <=== #1 Round 1 begins, before NTP is called
[0d00h00m35s] 2023-04-03T20:55:46 [SNTP] Time is synced with NTP Server de.pool.ntp.org: 2023-04-03 20:55:46
[0d00h01m08s] 2023-04-03T20:56:19 [POSTPROC] main: Raw: 0440.14046, Value: 440.14046, Status: no error
[0d00h01m08s] 2023-04-03T20:56:20 [TFLITE SERVER] Round #1 completed (56 seconds)
[0d00h05m03s] 2023-04-03T21:00:14 [TFLITE SERVER] Round #2 started
[0d00h05m46s] 2023-04-03T21:00:58 [POSTPROC] main: Raw: 0440.14046, Value: 440.14046, Status: no error
[0d00h05m47s] 2023-04-03T21:00:58 [TFLITE SERVER] Round #2 completed (44 seconds)

'''

@TopGoalVl TopGoalVl changed the title Wrong time in the first data- record / entry Round 1 begins before NTP is called (wrong timestamp) Apr 4, 2023
@jomjol
Copy link
Owner

jomjol commented Apr 5, 2023

This is already adressed and solved in the currrent rolling. Will go to the next release.

@jomjol jomjol closed this as completed Apr 5, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@jomjol @TopGoalVl