A similar result here also. I just dumbly had flogger write json of complete msg objects so not pasting it here.
I was getting:
09:32:00
10:32:00
11:32:00
12:32:00
13:32:00
...
etc.
But then I did a sudo reboot of the raspberry Pi and it started working fine.
If it's no trouble, I would appreciate if a few of you could leave the test flows running for 2-3 weeks to see if it happens. So far, it's been a week for me and not happened again.
I wonder how the clock in your Raspberry Pi is being updated. If you donĀ“t have a RTC module installed then the update is normally via internet connection. There are a few things that can do wrong with time update.
What is OS version in your Raspberry ? You can check with command line: lsb_release -a
What do you get if you issue below command ?
sudo systemctl status systemd-timesyncd
That is a good question (see the dump below below).
pi@raspberrypi:~ $ lsb_release -a
No LSB modules are available.
Distributor ID: Raspbian
Description: Raspbian GNU/Linux 10 (buster)
Release: 10
Codename: buster
pi@raspberrypi:~ $ sudo systemctl status systemd-timesyncd
Warning: The unit file, source configuration file or drop-ins of systemd-timesyncd.service changed on disk. Run 'systemctl daemon-reload' to reload units.
ā systemd-timesyncd.service - Network Time Synchronization
Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: enabled)
Drop-In: /lib/systemd/system/systemd-timesyncd.service.d
āādisable-with-time-daemon.conf
Active: active (running) since Thu 2020-07-23 10:23:22 AEST; 4 days ago
Docs: man:systemd-timesyncd.service(8)
Main PID: 278 (systemd-timesyn)
Status: "Synchronized to time server for the first time 193.40.0.5:123 (2.debian.pool.ntp.org)."
Tasks: 2 (limit: 2200)
Memory: 3.5M
CGroup: /system.slice/systemd-timesyncd.service
āā278 /lib/systemd/systemd-timesyncd
Jul 23 10:23:21 raspberrypi systemd[1]: Starting Network Time Synchronization...
Jul 23 10:23:22 raspberrypi systemd[1]: Started Network Time Synchronization.
Jul 23 10:24:03 raspberrypi systemd-timesyncd[278]: Synchronized to time server for the first time 193.40.0.5:123 (2.debian.pool.ntp.org).
Your results tell us that the systemd-timesync daemon is activated. This is good. Also shows that the time was synchronized with a time server a couple of days ago. It will be synchronized again after OS reboot (you know that as you mentioned in the OP that you could solve the issue rebooting the device every night). I understand that you will experience time drift between time syncs.
There is a way to force a time sync without a reboot.
You can do some experimentation with this sequence of commands (thanks if you can share afterwards):
timedatectl status
timedatectl timesync-status
journalctl -u systemd-timesyncd
sudo systemctl restart systemd-timesyncd
The last command is expected to resync.
You can now repeat the first three commands and see if the Raspberry time reflects the actual one (eliminating accumulated diffs).
I don't think it is the system time is it? The time readout is correctly shown as 09:32:00 isn't it?
Also any such error would be seen in the system clock itself (running date in a terminal for example).
I am not sure too. What makes me think it is worth investigating are these quoted statements:
I am sure if I force reboot the device every night it will hide the error
I have an update on this issue. It looks like some kind of clock issue which resolves itself if I do a sudo reboot of the Raspberry Pi.
But then I did a sudo reboot of the raspberry Pi and it started working fine.
I programmed on Raspberry Pi to send me a Telegram message every day at 5 pm. I just receive the first message, with a delay of 17 minutes. 
The flow inquires the Raspberry Pi clock and send the information along with other data. The clock received in the payload is 5:17pm.
My first thought now is that the issue is not related to the Raspberry Pi clock. Back to the square one in my investigation. Interesting case indeed.
Fantastic that it's not just me! 
I have not been able to reproduce it again yet, so I'll be patient.
If it happens to you again, please log into the Pi console and do a date command to see what time Raspbian thinks it is.
Ok, quick thought:
The time it does what ever gets later and later.
In the code when it sends the message, set a part of the message with the time it thinks it is.
The reasoning is:
You want this to happen at (eg) 17:00.
It is happening at 17:15.
You know it is 17:15, but does the machine?
If the message which is created at "17:00" has a (human readable) timestamp and it says 17:15...... Then you know the problem is else where.
But if it says 17:00 in the message and you see it is 17:15 (or what ever) you know it is clock drift.
That will/would/should go a long way to identify where the problem is.
This is not an attempt to solve the issue but more of a related speculation. Has anyone experimented what happens if a Node.js timer has been set using setTimeout and the system time is changed while it's running (NTP sync for example)?
From the perspective of the setTimeout function's API, I would expect it to trigger approximately after the given time in milliseconds even if the system time changes meanwhile. If this would be the case, then I could very well see it failing as a cron timer which should be tied to a date and time and not how far the scheduled time is related to the start time.
1 Like
That is an interesting thought. I wonder what happens if node red starts up before the network gets going so the time can sync.
At least the systemd service description on Linux requires network to start first (when installed using the official install script). But it likely does not guarantee for the time sync service to be started first, let alone a sync to complete first.
Hi Andrew, I hear you.
What I did in my first testing was to program the inject node to send a telegram message at 17:00. The inject node is connected to an exec node that read the system time with:
timedatectl status | grep -i 'local time' | cut -c 28-
This payload will be sent in a Telegram message.
My mobile phone receives the message at 17:17 and the message content says the system time was 17:17.
Event if the final behaviour is totally unexpected I have no reasons to believe there is any bug in the inject node. I did the above testing in a production machine that is under heavy load (just run Chrome on a Raspian Desktop to get your Raspberry Pi 3 on the knees). I ran the very same flow in a development machine (the difference it is Raspberry Pi 4 - I donĀ“t have right now a spare model 3). The final result is totally different. I am receiving the Telegram notifications exactly at the programmed time (10:00 and the payload says the system time , at the time the message was crafted was 10:00). Keep investigating.
Nice and interesting point ! Great insight.
My guess: setTimeout does not read system time for its working. It will launch a callback function within x milliseconds. We both agree on that.
Now, to the second point of your speculation. The inject node uses cron library and cron will read the system time. If I change the system time in the middle (and I understand that the fake clock in the Raspian OS does that from times to times) then we may observe some unexpected behaviour. Indeed good thought. I will try to simulate this case.
Edit: There is already someone digging into this kind of problem in cron library (used by Node-RED).
Yes, the network service is started, that does not mean WiFi is connected or the internet is accessible.
You could change the service to try to wait for them... but then you get into the situation where it won't start unless they are really running and occasionally you may want to do that... like when/if your internet connection is broken.
And of course (currently at least) there are two times a year when the clock do suddenly shift by an hour...
Quite a coincidence since it's been reported 3 hours ago!
according to who's clock ... ? 
1 Like
The system clock doesn't change, just the displayed local time. I assume the inject node (or the module it uses under the hood) copes with DST somehow.
