Bug 1684143 - systemd-timesyncd fails to start on Silverblue 29
Summary: systemd-timesyncd fails to start on Silverblue 29
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 29
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2019-02-28 14:42 UTC by Micah Abbott
Modified: 2019-11-27 22:38 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-11-27 22:38:52 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Micah Abbott 2019-02-28 14:42:09 UTC
On Fedora Silverblue 29 (29.20190226.0) the `systemd-timesyncd` service fails to start.


```
$ rpm -q systemd
systemd-239-12.git8bca462.fc29.x86_64
```

The service status shows:

```
$ systemctl status systemd-timesyncd 
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2019-02-26 14:11:56 EST; 1 day 19h ago
     Docs: man:systemd-timesyncd.service(8)
  Process: 969 ExecStart=/usr/lib/systemd/systemd-timesyncd (code=exited, status=226/NAMESPACE)
 Main PID: 969 (code=exited, status=226/NAMESPACE)

Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Service has no hold-off time (RestartSec=0), scheduling restart.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Scheduled restart job, restart counter is at 5.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: Stopped Network Time Synchronization.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Start request repeated too quickly.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: Failed to start Network Time Synchronization.
```

The journal:

```
$ journalctl -b -u systemd-timesyncd.service
-- Logs begin at Mon 2018-04-30 16:12:58 EDT, end at Thu 2019-02-28 09:33:40 EST. --
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: Starting Network Time Synchronization...
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[933]: systemd-timesyncd.service: Failed to set up mount namespacing: No such file or directory
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[933]: systemd-timesyncd.service: Failed at step NAMESPACE spawning /usr/lib/systemd/systemd-timesyncd: No such file or directory
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Main process exited, code=exited, status=226/NAMESPACE
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: Failed to start Network Time Synchronization.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Service has no hold-off time (RestartSec=0), scheduling restart.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Scheduled restart job, restart counter is at 1.
Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[1]: Stopped Network Time Synchronization.
...
```

No SELinux denials observed.

Comment 1 Colin Walters 2019-02-28 14:47:46 UTC
It's not enabled by default AFAIK; I think we use chronyd by default.  Did you choose to enable it?

But I just did `systemctl stop chronyd && systemctl start systemd-timesync` and it works fine:

```
# rpm-ostree status -b
State: idle
AutomaticUpdates: stage; rpm-ostreed-automatic.timer: last run 22h ago
BootedDeployment:
● ostree://fedora-silverblue:fedora/29/x86_64/silverblue
                   Version: 29.20190226.0 (2019-02-26T00:57:33Z)
                BaseCommit: fcd0e7bd18dfd7ab17d4ffb3fe303df6a40ab2cd00ce027f5e00313a2864866e
              GPGSignature: Valid signature by 5A03B4DD8254ECA02FDA1637A20AA56B429476B4
           LayeredPackages: emacs fedora-toolbox ffmpeg fuse-sshfs git-evtag gnome-tweak-tool gstreamer1-plugin-openh264 gstreamer1-plugins-ugly-free keepassx krb5-workstation libva-vdpau-driver libvirt
                            libvirt-client mozilla-openh264 opensc origin-clients pcsc-lite-ccid qemu-kvm strace tilix tmux virt-manager xsel ykclient ykpers
host:root@localhost srv/virt-images
# systemctl status systemd-timesyncd
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; disabled; vendor preset: disabled)
   Active: active (running) since Thu 2019-02-28 09:44:53 EST; 2min 37s ago
     Docs: man:systemd-timesyncd.service(8)
 Main PID: 3554 (systemd-timesyn)
   Status: "Synchronized to time server 23.131.160.7:123 (0.fedora.pool.ntp.org)."
    Tasks: 2 (limit: 4915)
   Memory: 1.8M
   CGroup: /system.slice/systemd-timesyncd.service
           └─3554 /usr/lib/systemd/systemd-timesyncd

Feb 28 09:44:53 localhost.localdomain systemd[1]: Starting Network Time Synchronization...
Feb 28 09:44:53 localhost.localdomain systemd[1]: Started Network Time Synchronization.
Feb 28 09:44:53 localhost.localdomain systemd-timesyncd[3554]: Synchronized to time server 23.131.160.7:123 (0.fedora.pool.ntp.org).
```

`Feb 26 14:11:56 mastershake.usersys.redhat.com systemd[933]: systemd-timesyncd.service: Failed to set up mount namespacing: No such file or directory`
is the relevant line here but there's a *lot* of possible causes for that.

Do you e.g. have `rpm-ostree usroverlay` active?

Comment 2 Micah Abbott 2019-02-28 15:51:09 UTC
@walters I don't have any overlays and on my host `chroynd` is enabled, but not active?  However, starting `chronyd` worked fine:

```
$ rpm-ostree status -b
State: idle
AutomaticUpdates: stage; rpm-ostreed-automatic.timer: last run 18h ago
Deployments:
● ostree://fedora-workstation:fedora/29/x86_64/silverblue
                   Version: 29.20190226.0 (2019-02-26T00:57:33Z)
                BaseCommit: fcd0e7bd18dfd7ab17d4ffb3fe303df6a40ab2cd00ce027f5e00313a2864866e
              GPGSignature: Valid signature by 5A03B4DD8254ECA02FDA1637A20AA56B429476B4
           LayeredPackages: cockpit-bridge compat-ffmpeg28 ffmpeg-libs krb5-workstation libvirt libvirt-client libvirt-daemon-kvm libvirt-devel qemu-kvm tmux vagrant-libvirt vim-enhanced virt-install virt-manager

$ systemctl status chronyd
● chronyd.service - NTP client/server
   Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled)
   Active: inactive (dead)
     Docs: man:chronyd(8)
           man:chrony.conf(5)

$ sudo systemctl start chronyd
$ sudo systemctl status chronyd
● chronyd.service - NTP client/server
   Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2019-02-28 10:42:33 EST; 5s ago
     Docs: man:chronyd(8)
           man:chrony.conf(5)
  Process: 14954 ExecStartPost=/usr/libexec/chrony-helper update-daemon (code=exited, status=0/SUCCESS)
  Process: 14946 ExecStart=/usr/sbin/chronyd $OPTIONS (code=exited, status=0/SUCCESS)
 Main PID: 14948 (chronyd)
    Tasks: 1 (limit: 4915)
   Memory: 1.7M
   CGroup: /system.slice/chronyd.service
           └─14948 /usr/sbin/chronyd

Feb 28 10:42:33 mastershake.usersys.redhat.com systemd[1]: Starting NTP client/server...
Feb 28 10:42:33 mastershake.usersys.redhat.com chronyd[14948]: chronyd version 3.4 starting (+CMDMON +NTP +REFCLOCK +RTC +PRIVDROP +SCFILTER +SIGND +ASYNCDNS +SECHASH +IPV6 +DEBUG)
Feb 28 10:42:33 mastershake.usersys.redhat.com chronyd[14948]: Frequency -12.344 +/- 0.027 ppm read from /var/lib/chrony/drift
Feb 28 10:42:33 mastershake.usersys.redhat.com chronyd[14948]: Using right/UTC timezone to obtain leap second data
Feb 28 10:42:33 mastershake.usersys.redhat.com systemd[1]: Started NTP client/server.

```


TBH, not 100% sure how I got to this point...I remember doing some investigation as a result of the Silverblue forum post:

https://discussion.fedoraproject.org/t/ntp-broken-on-silverblue-29/515/

...which is how I got around to filing this BZ.

Anyways, on another Silverblue host that I have installed, I tried starting `systemd-timesyncd` and got a separate error:

```
$ systemctl status chronyd                                                 
● chronyd.service - NTP client/server                                                       
   Loaded: loaded (/usr/lib/systemd/system/chronyd.service; enabled; vendor preset: enabled)                                     
   Active: active (running) since Wed 2019-01-30 15:51:50 EST; 4 weeks 0 days ago                                                                                                                                                                                                        
     Docs: man:chronyd(8)                                                                           
           man:chrony.conf(5)                                                                                    
 Main PID: 785 (chronyd)                                                                                                                                                                                                                                                                 
    Tasks: 1 (limit: 4915)                                                                                                                                                                                                                                                               
   Memory: 2.8M                                                                                                                                                                                                                                                                          
   CGroup: /system.slice/chronyd.service                                                       
           └─785 /usr/sbin/chronyd                                                          
                                                                                                                                 
Feb 28 05:06:07 frylock.usersys.redhat.com chronyd[785]: Source 2604:a880:800:10::610:3001 replaced with 69.174.161.5                                                                                                                                                                    
Feb 28 05:45:29 frylock.usersys.redhat.com chronyd[785]: Source 72.30.35.88 replaced with 69.36.182.57
Feb 28 06:23:10 frylock.usersys.redhat.com chronyd[785]: Source 2001:470:0:2c8::2 replaced with 138.68.46.177    
Feb 28 06:32:31 frylock.usersys.redhat.com chronyd[785]: Selected source 10.5.26.10                                                                                                                                                                                                      
Feb 28 07:04:26 frylock.usersys.redhat.com chronyd[785]: Source 66.228.42.59 replaced with 208.75.88.4                                                                                                                                                                                   
Feb 28 07:39:01 frylock.usersys.redhat.com chronyd[785]: Source 2620:6:2000:104::48 replaced with 45.76.244.193                                                                                                                                                                          
Feb 28 08:14:43 frylock.usersys.redhat.com chronyd[785]: Source 2001:19f0:8001:1de:5400:ff:fe60:f647 replaced with 216.229.0.50
Feb 28 08:50:42 frylock.usersys.redhat.com chronyd[785]: Source 69.174.161.5 replaced with 2600:3c01::f03c:91ff:febc:67d4
Feb 28 09:30:15 frylock.usersys.redhat.com chronyd[785]: Source 69.36.182.57 replaced with 2600:2600::99                         
Feb 28 10:07:18 frylock.usersys.redhat.com chronyd[785]: Source 138.68.46.177 replaced with 207.192.69.118                                                                                                                                                                               

$ sudo systemctl stop chronyd                                                                

$ sudo systemctl start systemd-timesyncd
Job for systemd-timesyncd.service failed because the control process exited with error code.
See "systemctl status systemd-timesyncd.service" and "journalctl -xe" for details.

$ sudo systemctl status systemd-timesyncd
● systemd-timesyncd.service - Network Time Synchronization
   Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Thu 2019-02-28 10:45:50 EST; 20s ago
     Docs: man:systemd-timesyncd.service(8)
  Process: 12323 ExecStart=/usr/lib/systemd/systemd-timesyncd (code=exited, status=238/STATE_DIRECTORY)
 Main PID: 12323 (code=exited, status=238/STATE_DIRECTORY)

Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Service has no hold-off time (RestartSec=0), scheduling restart.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Scheduled restart job, restart counter is at 5.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Stopped Network Time Synchronization.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Start request repeated too quickly.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Failed to start Network Time Synchronization.

$ sudo journalctl -r -b
...
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Reached target System Time Synchronized.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Failed to start Network Time Synchronization.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Start request repeated too quickly.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Stopped Network Time Synchronization.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Scheduled restart job, restart counter is at 5.
Feb 28 10:45:50 frylock.usersys.redhat.com audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-timesyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 28 10:45:50 frylock.usersys.redhat.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-timesyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Service has no hold-off time (RestartSec=0), scheduling restart.
Feb 28 10:45:50 frylock.usersys.redhat.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-timesyncd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Failed to start Network Time Synchronization.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Failed with result 'exit-code'.
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: systemd-timesyncd.service: Main process exited, code=exited, status=238/STATE_DIRECTORY
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[12323]: systemd-timesyncd.service: Failed at step STATE_DIRECTORY spawning /usr/lib/systemd/systemd-timesyncd: Permission denied
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[12323]: systemd-timesyncd.service: Failed to set up special execution directory in /var/lib: Permission denied
Feb 28 10:45:50 frylock.usersys.redhat.com audit[12323]: AVC avc:  denied  { setattr } for  pid=12323 comm="(imesyncd)" name="timesync" dev="dm-0" ino=3027048 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir permissive=0
Feb 28 10:45:50 frylock.usersys.redhat.com systemd[1]: Starting Network Time Synchronization...
...
```

This looks a little similar to BZ#1559286, but not exactly.

The smoking gun being:

`Feb 28 10:45:50 frylock.usersys.redhat.com audit[12323]: AVC avc:  denied  { setattr } for  pid=12323 comm="(imesyncd)" name="timesync" dev="dm-0" ino=3027048 scontext=system_u:system_r:init_t:s0 tcontext=system_u:object_r:var_lib_t:s0 tclass=dir permissive=0`


This matches some of what I reported in the Silverblue forum post I mentioned earlier.

Comment 3 Ben Cotton 2019-10-31 19:14:05 UTC
This message is a reminder that Fedora 29 is nearing its end of life.
Fedora will stop maintaining and issuing updates for Fedora 29 on 2019-11-26.
It is Fedora's policy to close all bug reports from releases that are no longer
maintained. At that time this bug will be closed as EOL if it remains open with a
Fedora 'version' of '29'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 29 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 4 Ben Cotton 2019-11-27 22:38:52 UTC
Fedora 29 changed to end-of-life (EOL) status on 2019-11-26. Fedora 29 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.


Note You need to log in before you can comment on or make changes to this bug.