MAAS

  1. Bug #1697209
  2. Comment #7

Comment 7 for bug 1697209

Revision history for this message
Marius Žalinauskas (marius-zalinauskas) wrote :

Looks like problems with AppArmour. Take a look at messages from /var/log/syslog:

Jun 29 14:10:54 16043 systemd[1]: Starting LSB: Start NTP daemon...
Jun 29 14:10:54 16043 ntp[2352]: * Starting NTP server ntpd
Jun 29 14:10:54 16043 ntpd[2362]: ntpd 4.2.8p4@1.3265-o Wed Apr 5 13:28:07 UTC 2017 (1): Starting
Jun 29 14:10:54 16043 ntpd[2362]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 112:116
Jun 29 14:10:54 16043 ntp[2352]: ...done.
Jun 29 14:10:54 16043 systemd[1]: Started LSB: Start NTP daemon.
Jun 29 14:10:54 16043 ntpd[2364]: proto: precision = 0.076 usec (-24)
Jun 29 14:10:54 16043 ntpd[2364]: Listen and drop on 0 v6wildcard [::]:123
Jun 29 14:10:54 16043 ntpd[2364]: Listen and drop on 1 v4wildcard 0.0.0.0:123
Jun 29 14:10:54 16043 ntpd[2364]: Listen normally on 2 lo 127.0.0.1:123
Jun 29 14:10:54 16043 ntpd[2364]: Listen normally on 3 enp3s0 93.115.27.45:123
Jun 29 14:10:54 16043 ntpd[2364]: Listen normally on 4 lo [::1]:123
Jun 29 14:10:54 16043 ntpd[2364]: Listen normally on 5 enp3s0 [fe80::202:c9ff:fe55:9ac0%4]:123
Jun 29 14:10:54 16043 ntpd[2364]: Listening on routing socket on fd #22 for interface updates
Jun 29 14:10:54 16043 cloud-init[1208]: Processing triggers for libc-bin (2.23-0ubuntu9) ...
Jun 29 14:10:54 16043 kernel: [ 40.880454] audit_printk_skb: 9 callbacks suppressed
Jun 29 14:10:54 16043 kernel: [ 40.880457] audit: type=1400 audit(1498745454.780:15): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/ntpd" pid=2373 comm="apparmor_parser"
Jun 29 14:10:54 16043 cloud-init[1208]: Processing triggers for systemd (229-4ubuntu17) ...
Jun 29 14:10:54 16043 systemd[1]: Reloading.
Jun 29 14:10:54 16043 systemd[1]: snapd.refresh.timer: Adding 5h 47min 45.349958s random time.
Jun 29 14:10:54 16043 systemd[1]: snapd.refresh.timer: Adding 23min 34.329195s random time.
Jun 29 14:10:54 16043 systemd[1]: Started ACPI event daemon.
Jun 29 14:10:54 16043 cloud-init[1208]: Processing triggers for ureadahead (0.100.0-19) ...
Jun 29 14:10:55 16043 systemd[1]: Stopping LSB: Start NTP daemon...
Jun 29 14:10:55 16043 ntp[2430]: * Stopping NTP server ntpd
Jun 29 14:10:55 16043 ntpd[2364]: ntpd exiting on signal 15 (Terminated)
Jun 29 14:10:55 16043 ntp[2430]: ...done.
Jun 29 14:10:55 16043 ntpd[2364]: 93.115.27.250 local addr 93.115.27.45 -> <null>
Jun 29 14:10:55 16043 systemd[1]: Stopped LSB: Start NTP daemon.
Jun 29 14:10:55 16043 systemd[1]: Starting LSB: Start NTP daemon...
Jun 29 14:10:55 16043 ntp[2443]: * Starting NTP server ntpd
Jun 29 14:10:55 16043 ntp[2443]: /usr/sbin/ntpd: error while loading shared libraries: libcap.so.2: cannot stat shared object: Permission denied
Jun 29 14:10:55 16043 ntp[2443]: ...fail!
Jun 29 14:10:55 16043 systemd[1]: ntp.service: Control process exited, code=exited status=127
Jun 29 14:10:55 16043 systemd[1]: Failed to start LSB: Start NTP daemon.
Jun 29 14:10:55 16043 systemd[1]: ntp.service: Unit entered failed state.
Jun 29 14:10:55 16043 systemd[1]: ntp.service: Failed with result 'exit-code'.
Jun 29 14:10:55 16043 kernel: [ 41.922900] audit: type=1400 audit(1498745455.824:16): apparmor="DENIED" operation="getattr" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/ntpd" name="overlay/etc/ld.so.cache" pid=2452 comm="ntpd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jun 29 14:10:55 16043 kernel: [ 41.922923] audit: type=1400 audit(1498745455.824:17): apparmor="DENIED" operation="getattr" info="Failed name lookup - disconnected path" error=-13 profile="/usr/sbin/ntpd" name="lib/x86_64-linux-gnu/libcap.so.2.24" pid=2452 comm="ntpd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Jun 29 14:10:55 16043 cloud-init[1208]: Cloud-init v. 0.7.9 running 'modules:config' at Thu, 29 Jun 2017 14:10:36 +0000. Up 22.41 seconds.
Jun 29 14:10:55 16043 cloud-init[1208]: 2017-06-29 14:10:55,829 - cc_ntp.py[ERROR]: Failed to reload/start ntp service: Unexpected error while running command.
Jun 29 14:10:55 16043 cloud-init[1208]: Command: ['systemctl', 'reload-or-restart', 'ntp']
Jun 29 14:10:55 16043 cloud-init[1208]: Exit code: 1
Jun 29 14:10:55 16043 cloud-init[1208]: Reason: -
Jun 29 14:10:55 16043 cloud-init[1208]: Stdout: -
Jun 29 14:10:55 16043 cloud-init[1208]: Stderr: Job for ntp.service failed because the control process exited with error code. See "systemctl status ntp.service" and "journalctl -xe" for details.
Jun 29 14:10:55 16043 cloud-init[1208]: Traceback (most recent call last):
Jun 29 14:10:55 16043 cloud-init[1208]: File "/usr/lib/python3/dist-packages/cloudinit/config/cc_ntp.py", line 78, in handle
Jun 29 14:10:55 16043 cloud-init[1208]: reload_ntp(systemd=cloud.distro.uses_systemd())
Jun 29 14:10:55 16043 cloud-init[1208]: File "/usr/lib/python3/dist-packages/cloudinit/config/cc_ntp.py", line 140, in reload_ntp
Jun 29 14:10:55 16043 cloud-init[1208]: util.subp(cmd, capture=True)
Jun 29 14:10:55 16043 cloud-init[1208]: File "/usr/lib/python3/dist-packages/cloudinit/util.py", line 1821, in subp
Jun 29 14:10:55 16043 cloud-init[1208]: cmd=args)
Jun 29 14:10:55 16043 cloud-init[1208]: cloudinit.util.ProcessExecutionError: Unexpected error while running command.
Jun 29 14:10:55 16043 cloud-init[1208]: Command: ['systemctl', 'reload-or-restart', 'ntp']
Jun 29 14:10:55 16043 cloud-init[1208]: Exit code: 1
Jun 29 14:10:55 16043 cloud-init[1208]: Reason: -
Jun 29 14:10:55 16043 cloud-init[1208]: Stdout: -
Jun 29 14:10:55 16043 cloud-init[1208]: Stderr: Job for ntp.service failed because the control process exited with error code. See "systemctl status ntp.service" and "journalctl -xe" for details.
Jun 29 14:10:55 16043 cloud-init[1208]: 2017-06-29 14:10:55,919 - util.py[WARNING]: Running module ntp (<module 'cloudinit.config.cc_ntp' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ntp.py'>) failed
Jun 29 14:10:56 16043 systemd-timesyncd[746]: Synchronized to time server 91.189.89.199:123 (ntp.ubuntu.com).
Jun 29 14:10:56 16043 systemd[1]: cloud-config.service: Main process exited, code=exited, status=1/FAILURE
Jun 29 14:10:56 16043 systemd[1]: Failed to start Apply the settings specified in cloud-config.
Jun 29 14:10:56 16043 systemd[1]: cloud-config.service: Unit entered failed state.
Jun 29 14:10:56 16043 systemd[1]: cloud-config.service: Failed with result 'exit-code'.
Jun 29 14:10:56 16043 systemd[1]: Starting Execute cloud user/final scripts...