Public bug reported:
- install unbound: sudo apt install unbound
- unbound automatic start after installation will work
steven@box:~$ sudo systemctl status unbound
● unbound.service - Unbound DNS server
Loaded: loaded (/lib/systemd/system/unbound.service; enabled; vendor preset:
enabled)
Active: active (running) since Mon 2017-10-16 10:05:55 CEST; 22s ago
Docs: man:unbound(8)
Main PID: 3016 (unbound)
Tasks: 1 (limit: 4915)
CGroup: /system.slice/unbound.service
└─3016 /usr/sbin/unbound -d
Oct 16 10:05:55 box systemd[1]: Starting Unbound DNS server...
Oct 16 10:05:55 box package-helper[3011]: /var/lib/unbound/root.key does not
exist, copying from /usr/share/dns/root.key
Oct 16 10:05:55 box package-helper[3011]: /var/lib/unbound/root.key has content
Oct 16 10:05:55 box package-helper[3011]: success: the anchor is ok
Oct 16 10:05:55 box unbound[3016]: [3016:0] notice: init module 0: subnet
Oct 16 10:05:55 box unbound[3016]: [3016:0] notice: init module 1: validator
Oct 16 10:05:55 box unbound[3016]: [3016:0] notice: init module 2: iterator
Oct 16 10:05:55 box unbound[3016]: [3016:0] info: start of service (unbound
1.6.5).
Oct 16 10:05:55 box systemd[1]: Started Unbound DNS server.
- try to (re)start unbound.service via systemctl and it will fail
- stopping unbound.service via systemctl will work
steven@box:~$ sudo systemctl start unbound
Job for unbound.service failed because a timeout was exceeded.
See "systemctl status unbound.service" and "journalctl -xe" for details.
- you will find an apparmor related entry in the logs/journal
...
Oct 16 10:41:31 box systemd[1]: Starting Unbound DNS server...
Oct 16 10:41:32 box package-helper[4480]: /var/lib/unbound/root.key has content
Oct 16 10:41:32 box package-helper[4480]: success: the anchor is ok
Oct 16 10:41:35 box unbound[4485]: [4485:0] notice: init module 0: subnet
Oct 16 10:41:35 box unbound[4485]: [4485:0] notice: init module 1: validator
Oct 16 10:41:35 box unbound[4485]: [4485:0] notice: init module 2: iterator
Oct 16 10:41:35 box unbound[4485]: [4485:0] info: start of service (unbound
1.6.5).
Oct 16 10:41:35 box audit[4485]: AVC apparmor="DENIED" operation="sendmsg"
profile="/usr/sbin/unbound" name="/run/systemd/notify" pid=4485 comm="unbound"
requested_mask="w" denied_mask="w" fsuid=118 ouid=0
Oct 16 10:41:35 box kernel: audit: type=1400 audit(1508143295.929:118):
apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/unbound"
name="/run/systemd/notify" pid=4485 comm="unbound" requested_mask="w" den
Oct 16 10:41:36 box sudo[4486]: steven : TTY=pts/1 ; PWD=/home/steven ;
USER=root ; COMMAND=/bin/journalctl
Oct 16 10:41:36 box sudo[4486]: pam_unix(sudo:session): session opened for user
root by (uid=0)
Oct 16 10:41:36 box sudo[4486]: pam_unix(sudo:session): session closed for user
root
Oct 16 10:41:59 box sudo[4490]: steven : TTY=pts/1 ; PWD=/home/steven ;
USER=root ; COMMAND=/bin/journalctl
Oct 16 10:41:59 box sudo[4490]: pam_unix(sudo:session): session opened for user
root by (uid=0)
Oct 16 10:41:59 box sudo[4490]: pam_unix(sudo:session): session closed for user
root
Oct 16 10:42:07 box sudo[4493]: steven : TTY=pts/1 ; PWD=/home/steven ;
USER=root ; COMMAND=/bin/journalctl
Oct 16 10:42:07 box sudo[4493]: pam_unix(sudo:session): session opened for user
root by (uid=0)
Oct 16 10:42:38 box dbus[1459]: apparmor="DENIED" operation="dbus_method_call"
bus="session" path="/org/gtk/vfs/mounttracker"
interface="org.gtk.vfs.MountTracker" member="ListMountableInfo" mask="send"
name=":1
Oct 16 10:43:02 box systemd[1]: unbound.service: Start operation timed out.
Terminating.
Oct 16 10:43:02 box audit[4485]: AVC apparmor="DENIED" operation="sendmsg"
profile="/usr/sbin/unbound" name="/run/systemd/notify" pid=4485 comm="unbound"
requested_mask="w" denied_mask="w" fsuid=118 ouid=0
Oct 16 10:43:02 box unbound[4485]: [4485:0] info: service stopped (unbound
1.6.5).
Oct 16 10:43:02 box kernel: audit: type=1400 audit(1508143382.772:119):
apparmor="DENIED" operation="sendmsg" profile="/usr/sbin/unbound"
name="/run/systemd/notify" pid=4485 comm="unbound" requested_mask="w" den
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: server stats for thread 0: 50
queries, 4 answers from cache, 46 recursions, 0 prefetch, 0 rejected by ip
ratelimiting
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: server stats for thread 0:
requestlist max 10 avg 1.45652 exceeded 0 jostled 0
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: average recursion processing
time 0.175267 sec
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: histogram of recursion
processing times
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: [25%]=0.0464213
median[50%]=0.0931301 [75%]=0.141995
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: lower(secs) upper(secs)
recursions
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.000000 0.000001 9
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.032768 0.065536 6
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.065536 0.131072 19
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.131072 0.262144 6
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.262144 0.524288 2
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 0.524288 1.000000 2
Oct 16 10:43:03 box unbound[4485]: [4485:0] info: 1.000000 2.000000 2
Oct 16 10:43:03 box systemd[1]: Failed to start Unbound DNS server.
Oct 16 10:43:03 box systemd[1]: unbound.service: Unit entered failed state.
Oct 16 10:43:03 box systemd[1]: unbound.service: Failed with result 'timeout'.
Oct 16 10:43:03 box sudo[4474]: pam_unix(sudo:session): session closed for user
root
Oct 16 10:43:03 box systemd[1]: unbound.service: Service hold-off time over,
scheduling restart.
Oct 16 10:43:03 box systemd[1]: Stopped Unbound DNS server.
...
- the important apparmor entry is
...
Oct 16 10:43:02 box audit[4485]: AVC apparmor="DENIED" operation="sendmsg"
profile="/usr/sbin/unbound" name="/run/systemd/notify" pid=4485 comm="unbound"
requested_mask="w" denied_mask="w" fsuid=118 ouid=0
...
- searching the internet shows similar issues, e.g. Bug 1530483
(https://bugs.launchpad.net/ubuntu/+source/rsyslog/+bug/1530483)
- so i can fix the issue with adding "/{,var/}run/systemd/notify w," to the
Unbound apparmor profile (/etc/apparmor.d/usr.sbin.unbound)
...
# Unix control socket
/{,var/}run/unbound.ctl rw,
/{,var/}run/systemd/notify w,
#include <local/usr.sbin.unbound>
}
...
- now i can (re)start unbound via "sudo systemctl restart unbound"
without issue
** Affects: unbound (Ubuntu)
Importance: Undecided
Status: New
--
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/1723900
Title:
unbound systemctl (re)start fails due to Apparmor profile issue
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/unbound/+bug/1723900/+subscriptions
--
ubuntu-bugs mailing list
ubuntu-bugs@lists.ubuntu.com
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs
