Closed borpin closed 5 years ago
@borpin Thanks for your report.
Date | Sat 22 Sep 15:59:50 BST 2018 ...
--2018-09-22 15:56:58--
Your system time is out of sync.
Please try to resolve by running /DietPi/dietpi/func/run_ntpd
, otherwise show output for investigation. It should in case of error also ask to check systemctl status systemd-timesyncd
to check time sync service status/error log.
In case of above shows error/failed timesync, perhaps the chosen NTP server is down or broken. If you are connected via router to the internet, most properly the router acts as NTP server as well. In this case it makes most sense to use it instead of external NTP servers. Go to dietpi-config > Network Options: Misc > NTP Mirror
and choose Gateway
. If this does not work, choose the Debian default: debian.pool.ntp.org
(Default
should automatically lead to local gateway/DHCP server is tried, otherwise fallback to the Debian pool)
Ok so I have raised this issue before (long time ago) and even blogged about it.
I selected daemon and drift in dietpi.txt
Checking the status of time sync produced this:
root@DietPi-Monitor:~# timedatectl status
Local time: Sat 2018-09-22 17:25:19 BST
Universal time: Sat 2018-09-22 16:25:19 UTC
RTC time: n/a
Time zone: Europe/London (BST, +0100)
Network time on: no
NTP synchronized: no
RTC in local TZ: no
what is required is timedatectl set-ntp true
. Rerunning the status command gives
root@DietPi-Monitor:~# timedatectl status
Local time: Thu 2018-10-25 21:44:58 BST
Universal time: Thu 2018-10-25 20:44:58 UTC
RTC time: n/a
Time zone: Europe/London (BST, +0100)
Network time on: yes
NTP synchronized: no
RTC in local TZ: no
which corrects the time but not the synchronization.
A restart of the service systemctl restart systemd-timesyncd.service
and the time is now OK.
root@DietPi-Monitor:~# timedatectl status
Local time: Thu 2018-10-25 21:50:51 BST
Universal time: Thu 2018-10-25 20:50:51 UTC
RTC time: n/a
Time zone: Europe/London (BST, +0100)
Network time on: yes
NTP synchronized: yes
RTC in local TZ: no
[edit] I did try /DietPi/dietpi/func/run_ntpd
but this will not correct the clock as the delta is too large.
[edit2] it does solve the original issue - edited title
@borpin
timedatectl set-ntp true
does nothing else than systemctl enable systemd-timesyncd
, which is what we do as well, when choosing daemon+drift method: https://github.com/Fourdee/DietPi/blob/master/dietpi/func/dietpi-set_software#L260
[edit] I did try /DietPi/dietpi/func/run_ntpd but this will not correct the clock as the delta is too large.
Hmm, run_ntpd
in every case does systemctl restart systemd-timesyncd
as well, even error handled: https://github.com/Fourdee/DietPi/blob/master/dietpi/func/run_ntpd#L41
So I am wondering, since choosing time sync daemon mode + run_ntpd (is called as well when choosing the time sync mode via dietpi-config: https://github.com/Fourdee/DietPi/blob/master/dietpi/dietpi-config#L1418) does exactly the same than what you did manually 🤔.
dietpi.txt
entry parsed and applied on first boot: https://github.com/Fourdee/DietPi/blob/master/dietpi/boot#L31
dietpi-config > Advanced Options
.Do you face any error or meaningful info output when running the DietPi script, or why do you think this will not correct the clock as the delta is too large
? I have no detailed insight, but it makes sense, that drift does only work, if the delta is not too large. But the DietPi scripts always do a service restart which initially should do a successful sync.
Do you face any error or meaningful info output when running the DietPi script, or why do you think this will not correct the clock as the delta is too large?
In my investigation last time, I came across this comment that if the delta was too big ntp would not correct the clock.
As this happens on first boot, I am unable to collect the output from the console.
The install is clearly not working when using the dietpi.txt method as the first output of timedatectl
above shows.
timedatectl set-ntp true
does nothing else thansystemctl enable systemd-timesyncd
I don't think that statement is correct. https://feeding.cloud.geek.nz/posts/time-synchronization-with-ntp-and-systemd/
The install is clearly not working when using the dietpi.txt method as the first output of timedatectl above shows.
I will try to replicate a fresh install with CONFIG_NTP_MODE=4
on first boot, perhaps we missed something.
The links about set-ntp
does not say how NTP sync is "enabled". However it's easy to test if the result is different than just enabling+starting the service.
But first I was in mood the try following the c code of the related systemd scripts 😃:
timedatectl set-ntp
sends a dbus message to timedated
, containing "SetNTP" + true/false input: https://github.com/systemd/systemd/blob/master/src/timedate/timedatectl.c#L269-L276timedated
checks if the timesyncd service file exists and current service state and finally sends another dbus message to the systemd manager, containing "EnableUnitFiles"/"DisableUnitFiles"/"StartUnit"/"StopUnit", based on input+state: https://github.com/systemd/systemd/blob/master/src/timedate/timedated.c#L868 https://github.com/systemd/systemd/blob/master/src/timedate/timedated.c#L419systemctl
command: https://github.com/systemd/systemd/blob/master/src/systemctl/systemctl.c#L6217Check man pages: https://manpages.debian.org/stretch/systemd/timedatectl.1.en.html#OPTIONS
This enables and starts, or disables and stops the systemd-timesyncd.service unit. It does not affect the state of any other, unrelated network time synchronization services that might be installed on the system. This command is hence mostly equivalent to: systemctl enable --now systemd-timesyncd.service and systemctl disable --now systemd-timesyncd.service, but is protected by a different access policy.
--now
argument, this starts the service besides only enabling (autostart on next boot): https://manpages.debian.org/stretch/systemd/systemctl.1.en.html#OPTIONS
When used with enable, the units will also be started. When used with disable or mask, the units will also be stopped. The start or stop operation is only carried out when the respective enable or disable operation has been successful.
Check on system:
root@VM-Stretch:~# systemctl daemon-reload
root@VM-Stretch:~# systemctl stop systemd-timesyncd
root@VM-Stretch:~# systemctl disable systemd-timesyncd
root@VM-Stretch:~# timedatectl set-ntp false
root@VM-Stretch:~# systemctl status systemd-timesyncd
● systemd-timesyncd.service - Network Time Synchronization
Loaded: loaded (/lib/systemd/system/systemd-timesyncd.service; disabled; vendor preset: enabled)
Drop-In: /lib/systemd/system/systemd-timesyncd.service.d
└─disable-with-time-daemon.conf
Active: inactive (dead)
Docs: man:systemd-timesyncd.service(8)
Oct 26 02:20:55 VM-Stretch systemd[1]: Stopping Network Time Synchronization...
Oct 26 02:20:55 VM-Stretch systemd[1]: Stopped Network Time Synchronization.
root@VM-Stretch:~# timedatectl set-time "2012-10-30 18:17:16"
root@VM-Stretch:~# timedatectl
Local time: Tue 2012-10-30 18:17:25 CET
Universal time: Tue 2012-10-30 17:17:25 UTC
RTC time: Tue 2012-10-30 17:17:26
Time zone: Europe/Berlin (CET, +0100)
Network time on: no
NTP synchronized: no
RTC in local TZ: no
root@VM-Stretch:~# systemctl start systemd-timesyncd
Warning: systemd-timesyncd.service changed on disk. Run 'systemctl daemon-reload' to reload units.
root@VM-Stretch:~# timedatectl
Local time: Fri 2018-10-26 02:22:20 CEST
Universal time: Fri 2018-10-26 00:22:20 UTC
RTC time: Tue 2012-10-30 17:17:54
Time zone: Europe/Berlin (CEST, +0200)
Network time on: no
NTP synchronized: no
RTC in local TZ: no
hwclock -w
systemctl daemon-reload
root@VM-Stretch:~# timedatectl
Local time: Fri 2018-10-26 02:29:59 CEST
Universal time: Fri 2018-10-26 00:29:59 UTC
RTC time: Fri 2018-10-26 00:29:59
Time zone: Europe/Berlin (CEST, +0200)
Network time on: no
NTP synchronized: yes
RTC in local TZ: no
At first seems to work well, but closed view:
Oct 30 18:18:01 VM-Stretch systemd[1]: Starting Network Time Synchronization...
Oct 30 18:18:02 VM-Stretch systemd-timesyncd[2886]: System clock time unset or jumped backwards, restoring from recorded timestamp: Fri 2018-10-26 02:33:06 CEST
Oct 26 02:33:06 VM-Stretch systemd[1]: Started Network Time Synchronization.
Oct 26 02:37:57 VM-Stretch systemd-timesyncd[2886]: Synchronized to time server 192.168.178.1:123 (192.168.178.1).
recorded timestamp
, afterwards actual time sync. Hmm how to remove the recorded timestamps? 🤔 Okay real life check on fresh image required. Will do that tomorrow.
Okay real life check on fresh image required. Will do that tomorrow.
Yes I think that is the only way. Add in an install of package 130 as part of the test as we know that will fail if the time has not been set properly at first boot. Risk that an intermediate boot will fix the time.
Cool. didn't know the --now argument
:smile: every day a learning day!
@borpin @MichaIng
Possible issue, if setting mode 4 in dietpi.txt
, this runs during boot
and will fail to install dbus
if time is out, before time sync update:
G_AG_CHECK_INSTALL_PREREQ dbus
systemctl enable systemd-timesyncd
systemctl start systemd-timesyncd
Also APT cache does not exist at this stage, we should move the apply of mode 4 to end of dietpi-software.
Although, dbus
isn't required for other modes, should not affect sync?
@Fourdee €: Ah great commit already done 👍.
Nope dbus
is not required, if we use systemctl
(instead of timedatectl
). I am not sure how to test well if both are really the same, since timesyncd always recovers some stored timestamps, when time was manually edited, but I think the documentation makes it more than clear.
Yeah G_AG_CHECK_INSTALL_PREREQ dbus
can be the reason, if a failure makes the script exit 🤔. We decided to still install dbus
to make timedatectl
available for users who expect it (even that it is not necessarily required).
€: I verified the error on fresh install. The screen I tried to make was a little to late, but I could see a failed dietpi-set_software
install and time was not synced afterwards. Makes sense since script exits before systemd-timesyncd service is enabled and started.
Jep lets move time sync mode apply to dietpi-software first run setup. Alternative would be to skip dbus install based on install stage and then only install dbus in dietpi-software 1st run setup, depending on ntp mode. But more complicated....
@borpin
Issue should now be resolved. However, I'll need to update our image to apply the new boot code. Will let you know when its ready.
RootFS expansion failing:
[FAILED] DietPi-Software | Free space check: path=/ | available=54 MB | required=500 MB
root@DietPi:~# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/root 559M 500M 47M 92% /
root@DietPi:~# cat /var/tmp/dietpi/logs/fs_partition_resize.log
[FAILED] Could not determine device ID from: /etc/.dietpi_hw_model_identifier
Still failing...
Croot@DietPi:~# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/root 539M 429M 99M 82% /
devtmpfs 484M 0 484M 0% /dev
tmpfs 489M 0 489M 0% /dev/shm
tmpfs 489M 13M 476M 3% /run
tmpfs 5.0M 0 5.0M 0% /run/lock
tmpfs 489M 0 489M 0% /sys/fs/cgroup
/dev/mmcblk0p1 42M 24M 18M 57% /boot
tmpfs 10M 1.5M 8.6M 15% /DietPi
tmpfs 50M 12K 50M 1% /var/log
tmpfs 488M 20K 488M 1% /tmp
root@DietPi:~# cat /var/tmp/dietpi/logs/
dietpi-boot.log dietpi-ramlog.log fs_partition_resize.log
dietpi-preboot.log dietpi-ramlog_store/
dietpi-ramdisk.log dietpi-software_apt.log
root@DietPi:~# cat /var/tmp/dietpi/logs/fs_partition_resize.log
[FAILED] Could not determine device ID from: /etc/.dietpi_hw_model_identifier
Assuming RPi
root@DietPi:~# TARGET_DEV=$(findmnt / -o source -n)
root@DietPi:~# TARGET_PARTITION=${TARGET_DEV##*p} # Last [0-9] after "p"
root@DietPi:~# TARGET_DRIVE=${TARGET_DRIVE%p[0-9]} # EG: /dev/mmcblk[0-9]
root@DietPi:~# echo $TARGET_PARTITION
2
root@DietPi:~# echo $TARGET_DRIVE
root@DietPi:~#
@borpin
Image updated, please try it and let us know if the issue is resolved with CONFIG_NTP_MODE=4
on 1st run and during software install:
https://dietpi.com/downloads/images/DietPi_RPi-ARMv6-Stretch.7z
Ok I'll try. Need to find a spare SD card first 😄
@borpin @Fourdee @MichaIng I'm ready to test it. Already burned to image prepared by @Fourdee to microSD, and have RPi Zero W. What kind of help is required? What output should I provide to help?
@troyane - my failure scenario was using the settings in dietpi.txt to:
If the package installs correctly and the output of timedatectl status
looks like this
Local time: Thu 2018-10-25 21:50:51 BST
Universal time: Thu 2018-10-25 20:50:51 UTC
RTC time: n/a
Time zone: Europe/London (BST, +0100)
Network time on: yes
NTP synchronized: yes
RTC in local TZ: no
(key info is the time is correct & Network time on: yes
& NTP synchronized: yes
) we are good to go.
Not had time nor a spare SD card as yet.
@borpin you wrote
my failure scenario was using the settings in dietpi.txt to:
- select mode 4 ntp sync
- auto install package 130.
Could you provide more information? Should I do this changes before first run? If so, please provide exact commands I need to put into dietpi.txt
.
@troyane
Thanks for helping out, appreciate it 👍
After writing a DietPi image, edit /boot/dietpi.txt
, change:
AUTO_SETUP_AUTOMATED=1
AUTO_SETUP_INSTALL_SOFTWARE_ID=130
CONFIG_NTP_MODE=4
Save changes, then power on the device. Check for any errors during installation.
@Fourdee I'm not sure if it is it related to this issue, but I can't boot. I've burned image to microSD (SanDisk Ultra 8gb) via Etcher. Edited /boot/dietpi.txt
as required. Connected my RPi Zero W v1.1 via UART and here is boot log. Looks like it stuck on that line and can't do anything.
Did you edit the wifi.txt file for your wifi settings? I missed that as well once.
@troyane
RPi Zero W v1.1 via UART
We disable serial after 1st run, you can set this in dietpi.txt
:
CONFIG_SERIAL_CONSOLE_ENABLE=1
@borpin 👍
If using WiFi also set in dietpi.txt
:
AUTO_SETUP_NET_WIFI_ENABLED=1
And enter creds in dietpi-wifi.txt
@Fourdee Thanks for comments. It was a bit consufing to me see that serial was turned off after 1st run. In any case, I've set all up, here is boot log:
After connecting to RPi via SSH I can see tonns of messages
[ INFO ] DietPi-Login | DietPi is currently installing and configuring your system. Please wait for this to complete, check back later.
for last half an hour (or even more).
UPD: Ctrl+C gives me access to terminal:
# timedatectl status
Failed to create bus connection: No such file or directory
I've tried
# /DietPi/dietpi/func/run_ntpd
[ OK ] Root access verified.
[ OK ] NTPD: time sync | Completed
@borpin
File system expansion and first run setup on boot script level worked well. After reboot first run update should be applied and first run setup on dietpi-software level. Could you check htop
to see which script hangs?
[FAILED] Failed to start serial-getty@ttyS1.service. See 'systemctl status serial-getty@ttyS1.service' for details.
We really need to mute or workaround those irritating error messages, since it is expected that not all serial devices are available on all systems: EG: for i in /*/systemd/system/serial-getty*.service; do systemctl disable ${i##*/systemd/system/}; done
@MichaIng I think you mean that for @troyane
[FAILED] Could not determine device ID from: /etc/.dietpi_hw_model_identifier
I noted this is the log (unrelated I grant you).
@borpin Jep, sorry and thanks for redirecting 🤣.
[FAILED] Could not determine device ID from: /etc/.dietpi_hw_model_identifier
Jep, this happens on RPis, where the exact model is determined differently. We should workaround this confusing error message in case of RPi.
@borpin File system expansion and first run setup on boot script level worked well. After reboot first run update should be applied and first run setup on dietpi-software level. Could you check
htop
to see which script hangs?
But how could I do that? As soon as I Ctrl+C the process will be killed. Already ssh'ed as root
and as dietpi
-- see the same messages on both sessions.
UPD: I got it. Have two sessions opened -- as root (with lines [ INFO ] DietPi-Login | DietPi is currently installing and configuring your system. Please wait for this to complete, check back later.
constantly appearing) and one with dietpi
. I can run htop
. Can't determine what is wrong.
@borpin
Thanks for screen. /DietPi/dietpi/dietpi-software
is still running from first run login script: https://github.com/Fourdee/DietPi/blob/master/dietpi/login#L186
If it has not yet finished, it seems to be stuck somewhere, sadly no external command can be seen that currently runs. Since CPU usage changes around 15% it is still doing something.
Luckily we log output of 1st run setup to a tmp log file. Hopefully that gives a hint: cat /tmp/dietpi-firstrun-setup.log
No success. Failed to install as time has not been corrected. I've a HDMI plugged in so no output I am afraid. Not sure how to connect terminal console.
[edit] First run - wrong type of PI (not wireless) Doh!
@borpin Ah lol now I see I mentioned the wrong person (again!), this was to @troyane 😅. I think the daemon+drift issue should be resolved with: https://github.com/Fourdee/DietPi/commit/d9ac484d324842fe4c924edc2a1c297edbc14371
@troyane
So I guess your issue is not related, or did you as well enable daemon+drift NTP mode within dietpi.txt?
DietPi-Software hangs or takes very long to apply first run setup. Please check cat /tmp/dietpi-firstrun-setup.log
to hopefully see where it currently hangs or is working on.
Ok, so that seems to have set the date correctly and I saw some time commands but timedatectl
returns Failed to create bus connection: no such file or directory
.
If I go into dietpi-config
, daemon + drift is selected, but if I select it again, dbus
is installed. Without a reboot, timedatectl
then works and gives the expected output.
Ha comments crossed. May be we are not seeing the issue as the delta is too great. I didn't apply the patch - how would I do that?
@MichaIng If this issues are not related, it will be much better to have separate issue.
cat /tmp/dietpi-firstrun-setup.log
blinks, but outputs nothing. I've opened this file via MC's View:
dietpi-firstrun-setup.log
To be clear how this file grows (but I can't see any significant changes except "tail" symbols you saw on gif):
$ uptime && ls -lah diet*
21:25:15 up 14 min, 2 users, load average: 1.91, 1.84, 1.24
-rw-r--r-- 1 root root 19K Oct 31 21:25 dietpi-firstrun-setup.log
and after some time:
$ uptime && ls -lah diet*
22:02:52 up 51 min, 2 users, load average: 1.76, 1.94, 1.92
-rw-r--r-- 1 root root 64K Oct 31 22:02 dietpi-firstrun-setup.log
@borpin
Thanks for testing 👍
Patch is applied to image updated 7 days ago: https://github.com/Fourdee/DietPi/issues/2181#issuecomment-433722969
Ok, so that seems to have set the date correctly and I saw some time commands but timedatectl returns Failed to create bus connection: no such file or directory. If I go into dietpi-config, daemon + drift is selected, but if I select it again, dbus is installed. Without a reboot, timedatectl then works and gives the expected output.
Did this occur using the above image?
Resolved on latest RPi image, passed our local testing. Will mark as completed.
Please reopen if the issue still occurs on latest image: https://github.com/Fourdee/DietPi/issues/2181#issuecomment-433722969
Constantly growing dietpi-firstrun-setup.log
@troyane Thanks for the report 👍
Appears dietpi-notify animation is causing most of this. Will open a new ticket and see if we can clean it up: https://github.com/Fourdee/DietPi/issues/2286
Details:
Steps to reproduce:
Expected behaviour:
Actual behaviour:
Extra details:
Additional logs: