Package: apparmor-profiles Version: 2.11.1-3 Severity: critical Justification: breaks unrelated software
Hello, I've started using apparmor very recently, and when I rebooted to activate the kernel part, I didn't notice the issue below.. but a couple reboots afterwards I couldn't obtain a DHCP address anymore for wired and wifi interfaces. >From what I could see, when dhclient6 gets called by network-manager, this program gets denied a bunch of operations which makes it not do what it's supposed to and just exit. The weird part that I don't understand yet is that I don't think I've installed or upgraded anything else since I enabled apparmor (so why didn't I see this in a more consistent manner?). In the syslog I found the following log lines that are relevant: Nov 11 16:53:14 boohn kernel: [ 15.622076] audit: type=1400 audit(1510437193.949:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="dhclient" pid=620 comm="apparmor_parser" Nov 11 16:53:20 boohn NetworkManager[678]: <info> [1510437200.9563] dhcp-init: Using DHCP client 'dhclient' Nov 11 16:53:24 boohn NetworkManager[678]: <info> [1510437204.1739] dhcp4 (eth0): dhclient started with pid 1184 Nov 11 16:53:24 boohn dhclient[1185]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:24 boohn kernel: [ 25.862578] audit: type=1400 audit(1510437204.189:74): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1185 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:24 boohn dhclient[1184]: DHCPREQUEST of 192.168.2.243 on eth0 to 255.255.255.255 port 67 Nov 11 16:53:24 boohn dhclient[1184]: DHCPNAK from 192.168.2.1 Nov 11 16:53:24 boohn dhclient[1186]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:24 boohn kernel: [ 25.887214] audit: type=1400 audit(1510437204.214:75): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1186 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:24 boohn kernel: [ 25.887967] audit: type=1400 audit(1510437204.215:76): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1187 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:24 boohn dhclient[1187]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:24 boohn dhclient[1184]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 Nov 11 16:53:24 boohn dhclient[1184]: DHCPREQUEST of 192.168.2.233 on eth0 to 255.255.255.255 port 67 Nov 11 16:53:24 boohn dhclient[1184]: DHCPOFFER of 192.168.2.233 from 192.168.2.1 Nov 11 16:53:24 boohn dhclient[1184]: DHCPACK of 192.168.2.233 from 192.168.2.1 Nov 11 16:53:24 boohn dhclient[1188]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:24 boohn kernel: [ 25.894073] audit: type=1400 audit(1510437204.221:77): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1188 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:24 boohn dhclient[1184]: bound to 192.168.2.233 -- renewal in 37728 seconds. Nov 11 16:53:26 boohn NetworkManager[678]: <info> [1510437206.3351] dhcp6 (eth0): dhclient started with pid 1189 Nov 11 16:53:26 boohn kernel: [ 28.012088] audit: type=1400 audit(1510437206.339:78): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-eth0.conf" pid=1189 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 Nov 11 16:53:26 boohn kernel: [ 28.012098] audit: type=1400 audit(1510437206.339:79): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-b63c69a8-9bf3-4eef-9610-09eee2527a06-eth0.lease" pid=1189 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 Nov 11 16:53:26 boohn kernel: [ 28.012104] audit: type=1400 audit(1510437206.339:80): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-b63c69a8-9bf3-4eef-9610-09eee2527a06-eth0.lease" pid=1189 comm="dhclient" requested_mask="wc" denied_mask="wc" fsuid=0 ouid=0 Nov 11 16:53:26 boohn dhclient[1189]: can't create /var/lib/NetworkManager/dhclient6-b63c69a8-9bf3-4eef-9610-09eee2527a06-eth0.lease: Permission denied Nov 11 16:53:26 boohn dhclient[1190]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:26 boohn dhclient[1189]: Created duid "\000\001\000\001!\232-\326\360\336\361+\253L". Nov 11 16:53:26 boohn dhclient[1189]: can't create /var/lib/NetworkManager/dhclient6-b63c69a8-9bf3-4eef-9610-09eee2527a06-eth0.lease: Permission denied Nov 11 16:53:26 boohn dhclient[1189]: Can't create /run/dhclient6-eth0.pid: Permission denied Nov 11 16:53:26 boohn kernel: [ 28.012575] audit: type=1400 audit(1510437206.339:81): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1190 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:26 boohn kernel: [ 28.013580] audit: type=1400 audit(1510437206.340:82): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-b63c69a8-9bf3-4eef-9610-09eee2527a06-eth0.lease" pid=1189 comm="dhclient" requested_mask="wc" denied_mask="wc" fsuid=0 ouid=0 Nov 11 16:53:26 boohn kernel: [ 28.013642] audit: type=1400 audit(1510437206.341:83): apparmor="DENIED" operation="mknod" profile="dhclient" name="/run/dhclient6-eth0.pid" pid=1189 comm="dhclient" requested_mask="c" denied_mask="c" fsuid=0 ouid=0 Nov 11 16:53:26 boohn dhclient[1189]: XMT: Solicit on eth0, interval 1020ms. Nov 11 16:53:26 boohn dhclient[1189]: RCV: Advertise message on eth0 from fe80::223:69ff:febf:3d6e. Nov 11 16:53:27 boohn dhclient[1189]: XMT: Solicit on eth0, interval 2100ms. Nov 11 16:53:27 boohn dhclient[1189]: RCV: Advertise message on eth0 from fe80::223:69ff:febf:3d6e. Nov 11 16:53:29 boohn NetworkManager[678]: <info> [1510437209.3970] dhcp4 (wlan0): dhclient started with pid 1214 Nov 11 16:53:29 boohn dhclient[1215]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:29 boohn kernel: [ 31.075386] audit: type=1400 audit(1510437209.402:84): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1215 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:29 boohn dhclient[1214]: DHCPREQUEST of 192.168.2.215 on wlan0 to 255.255.255.255 port 67 Nov 11 16:53:29 boohn dhclient[1214]: DHCPACK of 192.168.2.215 from 192.168.2.1 Nov 11 16:53:29 boohn dhclient[1216]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:29 boohn kernel: [ 31.110227] audit: type=1400 audit(1510437209.437:85): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1216 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:29 boohn dhclient[1214]: bound to 192.168.2.215 -- renewal in 38417 seconds. Nov 11 16:53:29 boohn dhclient[1189]: XMT: Solicit on eth0, interval 4260ms. Nov 11 16:53:29 boohn dhclient[1189]: RCV: Advertise message on eth0 from fe80::223:69ff:febf:3d6e. Nov 11 16:53:31 boohn NetworkManager[678]: <info> [1510437211.4239] dhcp6 (wlan0): dhclient started with pid 1221 Nov 11 16:53:31 boohn dhclient[1221]: can't create /var/lib/NetworkManager/dhclient6-fabf53ca-ae6c-42c6-b9e8-51bce175d379-wlan0.lease: Permission denied Nov 11 16:53:31 boohn dhclient[1222]: execve (/usr/lib/NetworkManager/nm-dhcp-helper, ...): Permission denied Nov 11 16:53:31 boohn dhclient[1221]: Created duid "\000\001\000\001!\232-\333\000$\327iQ\244". Nov 11 16:53:31 boohn dhclient[1221]: can't create /var/lib/NetworkManager/dhclient6-fabf53ca-ae6c-42c6-b9e8-51bce175d379-wlan0.lease: Permission denied Nov 11 16:53:31 boohn dhclient[1221]: Can't create /run/dhclient6-wlan0.pid: Permission denied Nov 11 16:53:31 boohn kernel: [ 33.100723] audit: type=1400 audit(1510437211.428:86): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-wlan0.conf" pid=1221 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 Nov 11 16:53:31 boohn kernel: [ 33.100730] audit: type=1400 audit(1510437211.428:87): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-fabf53ca-ae6c-42c6-b9e8-51bce175d379-wlan0.lease" pid=1221 comm="dhclient" requested_mask="r" denied_mask="r" fsuid=0 ouid=0 Nov 11 16:53:31 boohn kernel: [ 33.100734] audit: type=1400 audit(1510437211.428:88): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-fabf53ca-ae6c-42c6-b9e8-51bce175d379-wlan0.lease" pid=1221 comm="dhclient" requested_mask="wc" denied_mask="wc" fsuid=0 ouid=0 Nov 11 16:53:31 boohn kernel: [ 33.101133] audit: type=1400 audit(1510437211.428:89): apparmor="DENIED" operation="exec" profile="dhclient" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=1222 comm="dhclient" requested_mask="x" denied_mask="x" fsuid=0 ouid=0 Nov 11 16:53:31 boohn kernel: [ 33.102095] audit: type=1400 audit(1510437211.429:90): apparmor="DENIED" operation="open" profile="dhclient" name="/var/lib/NetworkManager/dhclient6-fabf53ca-ae6c-42c6-b9e8-51bce175d379-wlan0.lease" pid=1221 comm="dhclient" requested_mask="wc" denied_mask="wc" fsuid=0 ouid=0 Nov 11 16:53:31 boohn kernel: [ 33.102155] audit: type=1400 audit(1510437211.429:91): apparmor="DENIED" operation="mknod" profile="dhclient" name="/run/dhclient6-wlan0.pid" pid=1221 comm="dhclient" requested_mask="c" denied_mask="c" fsuid=0 ouid=0 Nov 11 16:54:09 boohn NetworkManager[678]: <warn> [1510437249.3316] dhcp4 (eth0): request timed out Nov 11 16:54:09 boohn NetworkManager[678]: <info> [1510437249.3317] dhcp4 (eth0): state changed unknown -> timeout Nov 11 16:54:09 boohn NetworkManager[678]: <info> [1510437249.3641] dhcp4 (eth0): canceled DHCP transaction, DHCP client pid 1184 Nov 11 16:54:09 boohn NetworkManager[678]: <info> [1510437249.3642] dhcp4 (eth0): state changed timeout -> done Nov 11 16:54:11 boohn NetworkManager[678]: <warn> [1510437251.3298] dhcp6 (eth0): request timed out Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3299] dhcp6 (eth0): state changed unknown -> timeout Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3308] dhcp6 (eth0): canceled DHCP transaction, DHCP client pid 1189 Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3308] dhcp6 (eth0): state changed timeout -> done Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3317] device (eth0): state change: ip-config -> ip-check (reason 'none', internal state 'managed') Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3327] device (eth0): state change: ip-check -> secondaries (reason 'none', internal state 'managed') Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3335] device (eth0): state change: secondaries -> activated (reason 'none', internal state 'managed') Nov 11 16:54:11 boohn NetworkManager[678]: <info> [1510437251.3561] device (eth0): Activation: successful, device activated. Nov 11 16:54:11 boohn dbus-daemon[672]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.7' (uid=0 pid=678 comm="/usr/sbin/NetworkManager --no-daemon ") Nov 11 16:54:11 boohn systemd[1]: Starting Network Manager Script Dispatcher Service... Nov 11 16:54:11 boohn dbus-daemon[672]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher' Nov 11 16:54:11 boohn systemd[1]: Started Network Manager Script Dispatcher Service. Nov 11 16:54:11 boohn nm-dispatcher: req:1 'up' [eth0]: new request (2 scripts) Nov 11 16:54:11 boohn nm-dispatcher: req:1 'up' [eth0]: start running ordered scripts... Nov 11 16:54:14 boohn NetworkManager[678]: <warn> [1510437254.3307] dhcp4 (wlan0): request timed out Nov 11 16:54:14 boohn NetworkManager[678]: <info> [1510437254.3308] dhcp4 (wlan0): state changed unknown -> timeout Nov 11 16:54:14 boohn NetworkManager[678]: <info> [1510437254.3472] dhcp4 (wlan0): canceled DHCP transaction, DHCP client pid 1214 Nov 11 16:54:14 boohn NetworkManager[678]: <info> [1510437254.3472] dhcp4 (wlan0): state changed timeout -> done Nov 11 16:54:16 boohn NetworkManager[678]: <warn> [1510437256.3290] dhcp6 (wlan0): request timed out Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3291] dhcp6 (wlan0): state changed unknown -> timeout Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3299] dhcp6 (wlan0): canceled DHCP transaction, DHCP client pid 1221 Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3300] dhcp6 (wlan0): state changed timeout -> done Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3308] device (wlan0): state change: ip-config -> ip-check (reason 'none', internal state 'managed') Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3317] device (wlan0): state change: ip-check -> secondaries (reason 'none', internal state 'managed') Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3323] device (wlan0): state change: secondaries -> activated (reason 'none', internal state 'managed') Nov 11 16:54:16 boohn NetworkManager[678]: <info> [1510437256.3327] manager: NetworkManager state is now CONNECTED_LOCAL according to the logs I did send a dhcp broadcast and got a response, network-manager even was convinced that the interfaces were up and configured, but according to "ip addr" neither eth0 nor wlan0 had an IP. there's a lot of errors in the log lines that are about things for dhclient6. I don't have IPv6 so I'm not sure that it's relevant to the fact that I wasn't able to get an IP assigned to any interface. To fix this, I used "aa-complain sbin.dhclient", then rebooted (mostly cause I don't know how to make sure the new profile is being used or not) and then I was able to connect to the network again and in the logs, opreations started showing with ACCEPT instead of DENIED. I'm still a bit mystified by this change.. I would have expected aa-complain to make the profile report the same denials but them not blocking anything. fwiw, I've kept the log file around so if you need more info from there I can dig further. -- System Information: Debian Release: buster/sid APT prefers unstable APT policy: (500, 'unstable') Architecture: amd64 (x86_64) Kernel: Linux 4.13.0-1-amd64 (SMP w/4 CPU cores) Locale: LANG=en_CA.utf8, LC_CTYPE=en_CA.utf8 (charmap=UTF-8) (ignored: LC_ALL set to en_CA.utf8), LANGUAGE=en_CA.utf8 (charmap=UTF-8) (ignored: LC_ALL set to en_CA.utf8) Shell: /bin/sh linked to /bin/dash Init: systemd (via /run/systemd/system) Versions of packages apparmor-profiles depends on: ii apparmor 2.11.1-3 apparmor-profiles recommends no packages. apparmor-profiles suggests no packages. -- no debconf information
