BUG: unable to handle kernel NULL pointer dereference

[Jonas Holmgren]

The latest update from the Xenial InRelease repository makes the following processes consume 100% CPU:

thermald (1.5-2ubuntu2)
imap (Dovecot 1:2.2.22-1ubuntu2)
imap-login (Dovecot 1:2.2.22-1ubuntu2)

and eventualy (after 1-2 minutes) render the system completely unresponsive.
"NMI watchdog: Watchdog detected hard LOCKUP on cpu 0".

I was able to recreate the problem on my test system, so whatever is missing in this report should be easy to simulate on another system. All apparmor profiles are standard.

# aa-status
apparmor module is loaded.
49 profiles are loaded.
13 profiles are in enforce mode.
   /sbin/dhclient
   /usr/bin/freshclam
   /usr/lib/NetworkManager/nm-dhcp-client.action
   /usr/lib/NetworkManager/nm-dhcp-helper
   /usr/lib/chromium-browser/chromium-browser//browser_java
   /usr/lib/chromium-browser/chromium-browser//browser_openjdk
   /usr/lib/chromium-browser/chromium-browser//sanitized_helper
   /usr/lib/connman/scripts/dhclient-script
   /usr/sbin/clamd
   /usr/sbin/mysqld
   /usr/sbin/named
   /usr/sbin/ntpd
   /usr/sbin/tcpdump
36 profiles are in complain mode.
   /usr/lib/chromium-browser/chromium-browser
   /usr/lib/chromium-browser/chromium-browser//chromium_browser_sandbox
   /usr/lib/chromium-browser/chromium-browser//lsb_release
   /usr/lib/chromium-browser/chromium-browser//xdgsettings
   /usr/lib/dovecot/anvil
   /usr/lib/dovecot/auth
   /usr/lib/dovecot/config
   /usr/lib/dovecot/deliver
   /usr/lib/dovecot/dict
   /usr/lib/dovecot/dovecot-lda
   /usr/lib/dovecot/dovecot-lda///usr/sbin/sendmail
   /usr/lib/dovecot/imap
   /usr/lib/dovecot/imap-login
   /usr/lib/dovecot/lmtp
   /usr/lib/dovecot/log
   /usr/lib/dovecot/managesieve
   /usr/lib/dovecot/managesieve-login
   /usr/lib/dovecot/pop3
   /usr/lib/dovecot/pop3-login
   /usr/lib/dovecot/ssl-params
   /usr/sbin/avahi-daemon
   /usr/sbin/dnsmasq
   /usr/sbin/dnsmasq//libvirt_leaseshelper
   /usr/sbin/dovecot
   /usr/sbin/identd
   /usr/sbin/mdnsd
   /usr/sbin/nmbd
   /usr/sbin/nscd
   /usr/sbin/smbd
   /usr/sbin/smbldap-useradd
   /usr/sbin/smbldap-useradd///etc/init.d/nscd
   /usr/{sbin/traceroute,bin/traceroute.db}
   /{usr/,}bin/ping
   klogd
   syslog-ng
   syslogd
25 processes have profiles defined.
5 processes are in enforce mode.
   /usr/bin/freshclam (2942)
   /usr/sbin/clamd (3080)
   /usr/sbin/mysqld (3767)
   /usr/sbin/named (3634)
   /usr/sbin/ntpd (3468)
20 processes are in complain mode.
   /usr/lib/dovecot/anvil (3827)
   /usr/lib/dovecot/auth (3845)
   /usr/lib/dovecot/auth (4503)
   /usr/lib/dovecot/config (3830)
   /usr/lib/dovecot/imap (6139)
   /usr/lib/dovecot/imap (6952)
   /usr/lib/dovecot/imap-login (3826)
   /usr/lib/dovecot/imap-login (3832)
   /usr/lib/dovecot/imap-login (6048)
   /usr/lib/dovecot/imap-login (7924)
   /usr/lib/dovecot/imap-login (12248)
   /usr/lib/dovecot/imap-login (12740)
   /usr/lib/dovecot/imap-login (12816)
   /usr/lib/dovecot/imap-login (14112)
   /usr/lib/dovecot/imap-login (14508)
   /usr/lib/dovecot/imap-login (14533)
   /usr/lib/dovecot/log (3828)
   /usr/lib/dovecot/managesieve-login (12794)
   /usr/lib/dovecot/ssl-params (4498)
   /usr/sbin/dovecot (3816)
0 processes are unconfined but have a profile defined.

# uname -r
4.4.0-34-generic

# apt-get install apparmor
Reading package lists... Done
Building dependency tree
Reading state information... Done
Suggested packages:
  apparmor-profiles-extra apparmor-docs apparmor-utils
The following packages will be upgraded:
  apparmor
1 upgraded, 0 newly installed, 0 to remove and 1 not upgraded.
Need to get 446 kB of archives.
After this operation, 4,096 B of additional disk space will be used.
Get:1 http://se.archive.ubuntu.com/ubuntu xenial-updates/main amd64 apparmor amd64 2.10.95-0ubuntu2.2 [446 kB]
Fetched 446 kB in 0s (4,172 kB/s)
Preconfiguring packages ...
(Reading database ... 115108 files and directories currently installed.)
Preparing to unpack .../apparmor_2.10.95-0ubuntu2.2_amd64.deb ...
Unpacking apparmor (2.10.95-0ubuntu2.2) over (2.10.95-0ubuntu2) ...
Processing triggers for systemd (229-4ubuntu7) ...
Processing triggers for ureadahead (0.100.0-19) ...
Processing triggers for man-db (2.7.5-1) ...
Setting up apparmor (2.10.95-0ubuntu2.2) ...
Installing new version of config file /etc/apparmor.d/abstractions/dbus-session-strict ...
update-rc.d: warning: start and stop actions are no longer supported; falling back to defaults

/var/log/kern.log:
Aug 19 22:52:05 beta kernel: [714135.698652] audit: type=1400 audit(1471639925.925:2053): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/{usr/,}bin/ping" pid=9270 comm="apparmor_parser"
Aug 19 22:52:05 beta kernel: [714135.761699] audit: type=1400 audit(1471639925.985:2054): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="klogd" pid=9273 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.854113] audit: type=1400 audit(1471639926.081:2055): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/sbin/dhclient" pid=9271 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.854450] audit: type=1400 audit(1471639926.081:2056): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=9271 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.854834] audit: type=1400 audit(1471639926.081:2057): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=9271 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.855118] audit: type=1400 audit(1471639926.081:2058): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=9271 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.859237] audit: type=1400 audit(1471639926.085:2059): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="syslogd" pid=9275 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714135.971474] audit: type=1400 audit(1471639926.197:2060): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="syslog-ng" pid=9277 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714136.022994] audit: type=1400 audit(1471639926.249:2061): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="/usr/lib/dovecot/anvil" pid=9281 comm="apparmor_parser"
Aug 19 22:52:06 beta kernel: [714136.023132] ------------[ cut here ]------------
Aug 19 22:52:06 beta kernel: [714136.023191] WARNING: CPU: 1 PID: 9281 at /build/linux-5vkMGy/linux-4.4.0/security/apparmor/label.c:142 profile_cmp+0xed/0x180()
Aug 19 22:52:06 beta kernel: [714136.023193] AppArmor WARN profile_cmp: ((!b)):
Aug 19 22:52:06 beta kernel: [714136.023197] Modules linked in: udp_diag tcp_diag inet_diag nfnetlink_queue nfnetlink_log nfnetlink bluetooth xt_recent binfmt_misc btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c vmw_vsock_vmci_transport vsock ppdev coretemp crct10dif_pclmul crc32_pclmul vmw_balloon cryptd joydev input_leds serio_raw 8250_fintek parport_pc shpchp vmw_vmci i2c_piix4 mac_hid ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 xt_hl nf_conntrack_ipv6 nf_defrag_ipv6 ip6t_rt ipt_REJECT nf_reject_ipv4 xt_comment nf_log_ipv4 nf_log_common xt_LOG xt_multiport xt_limit xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_addrtype xt_conntrack ip6table_filter ip6_tables nf_conntrack_netbios_ns nf_conntrack_broadcast nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack iptable_filter ip_tables x_tables lp parport autofs4 psmouse vmxnet3 vmwgfx ttm vmw_pvscsi drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops pata_acpi drm floppy fjes
Aug 19 22:52:06 beta kernel: [714136.023318] CPU: 1 PID: 9281 Comm: apparmor_parser Not tainted 4.4.0-34-generic #53-Ubuntu
Aug 19 22:52:06 beta kernel: [714136.023320] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/14/2014
Aug 19 22:52:06 beta kernel: [714136.023322] 0000000000000086 0000000008f1575b ffff880008b87c00 ffffffff813f11b3
Aug 19 22:52:06 beta kernel: [714136.023324] ffff880008b87c48 ffffffff81cf08e8 ffff880008b87c38 ffffffff81081102
Aug 19 22:52:06 beta kernel: [714136.023326] ffff88003c0a8400 0000000000000000 0000000000000009 0000000000000000
Aug 19 22:52:06 beta kernel: [714136.023328] Call Trace:
Aug 19 22:52:06 beta kernel: [714136.023346] [<ffffffff813f11b3>] dump_stack+0x63/0x90
Aug 19 22:52:06 beta kernel: [714136.023360] [<ffffffff81081102>] warn_slowpath_common+0x82/0xc0
Aug 19 22:52:06 beta kernel: [714136.023362] [<ffffffff8108119c>] warn_slowpath_fmt+0x5c/0x80
Aug 19 22:52:06 beta kernel: [714136.023369] [<ffffffff813ffc40>] ? u32_swap+0x10/0x10
Aug 19 22:52:06 beta kernel: [714136.023371] [<ffffffff8139072d>] profile_cmp+0xed/0x180
Aug 19 22:52:06 beta kernel: [714136.023373] [<ffffffff81391843>] aa_vec_unique+0x163/0x240
Aug 19 22:52:06 beta kernel: [714136.023376] [<ffffffff81395ab7>] __aa_labelset_update_subtree+0x687/0x820
Aug 19 22:52:06 beta kernel: [714136.023379] [<ffffffff8138897b>] aa_replace_profiles+0x59b/0xb70
Aug 19 22:52:06 beta kernel: [714136.023388] [<ffffffff811ecf4e>] ? __kmalloc+0x22e/0x250
Aug 19 22:52:06 beta kernel: [714136.023391] [<ffffffff8137d69f>] policy_update+0x9f/0x1f0
Aug 19 22:52:06 beta kernel: [714136.023393] [<ffffffff8137d803>] profile_replace+0x13/0x20
Aug 19 22:52:06 beta kernel: [714136.023401] [<ffffffff8120c9d8>] __vfs_write+0x18/0x40
Aug 19 22:52:06 beta kernel: [714136.023403] [<ffffffff8120d369>] vfs_write+0xa9/0x1a0
Aug 19 22:52:06 beta kernel: [714136.023406] [<ffffffff8120c2ff>] ? do_sys_open+0x1bf/0x2a0
Aug 19 22:52:06 beta kernel: [714136.023408] [<ffffffff8120e025>] SyS_write+0x55/0xc0
Aug 19 22:52:06 beta kernel: [714136.023421] [<ffffffff8182def2>] entry_SYSCALL_64_fastpath+0x16/0x71
Aug 19 22:52:06 beta kernel: [714136.023423] ---[ end trace 9f21e4366b6b8d2d ]---
Aug 19 22:52:06 beta kernel: [714136.023437] BUG: unable to handle kernel NULL pointer dereference at 0000000000000038
Aug 19 22:52:06 beta kernel: [714136.023531] IP: [<ffffffff8139066f>] profile_cmp+0x2f/0x180
Aug 19 22:52:06 beta kernel: [714136.023596] PGD 35afe067 PUD 3d556067 PMD 0
Aug 19 22:52:06 beta kernel: [714136.023694] Oops: 0000 [#1] SMP
Aug 19 22:52:06 beta kernel: [714136.023755] Modules linked in: udp_diag tcp_diag inet_diag nfnetlink_queue nfnetlink_log nfnetlink bluetooth xt_recent binfmt_misc btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs xfs libcrc32c vmw_vsock_vmci_transport vsock ppdev coretemp crct10dif_pclmul crc32_pclmul vmw_balloon cryptd joydev input_leds serio_raw 8250_fintek parport_pc shpchp vmw_vmci i2c_piix4 mac_hid ip6t_REJECT nf_reject_ipv6 nf_log_ipv6 xt_hl nf_conntrack_ipv6 nf_defrag_ipv6 ip6t_rt ipt_REJECT nf_reject_ipv4 xt_comment nf_log_ipv4 nf_log_common xt_LOG xt_multiport xt_limit xt_tcpudp nf_conntrack_ipv4 nf_defrag_ipv4 xt_addrtype xt_conntrack ip6table_filter ip6_tables nf_conntrack_netbios_ns nf_conntrack_broadcast nf_nat_ftp nf_nat nf_conntrack_ftp nf_conntrack iptable_filter ip_tables x_tables lp parport autofs4 psmouse vmxnet3 vmwgfx ttm vmw_pvscsi drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops pata_acpi drm floppy fjes
Aug 19 22:52:06 beta kernel: [714136.024610] CPU: 1 PID: 9281 Comm: apparmor_parser Tainted: G W 4.4.0-34-generic #53-Ubuntu
Aug 19 22:52:06 beta kernel: [714136.024689] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 04/14/2014
Aug 19 22:52:06 beta kernel: [714136.024737] task: ffff880026688cc0 ti: ffff880008b84000 task.ti: ffff880008b84000
Aug 19 22:52:06 beta kernel: [714136.024770] RIP: 0010:[<ffffffff8139066f>] [<ffffffff8139066f>] profile_cmp+0x2f/0x180
Aug 19 22:52:06 beta kernel: [714136.024823] RSP: 0018:ffff880008b87cb0 EFLAGS: 00010086
Aug 19 22:52:06 beta kernel: [714136.025096] RAX: 0000000000000000 RBX: ffff88003c0a8400 RCX: 0000000000000006
Aug 19 22:52:06 beta kernel: [714136.025170] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000009
Aug 19 22:52:06 beta kernel: [714136.025281] RBP: ffff880008b87cc0 R08: 000000005b2d2d2d R09: 00000000000084d1
Aug 19 22:52:06 beta kernel: [714136.025355] R10: 69666f7270204e52 R11: 00000000000084d1 R12: 0000000000000000
Aug 19 22:52:06 beta kernel: [714136.025425] R13: 0000000000000009 R14: 0000000000000000 R15: ffff88003503d050
Aug 19 22:52:06 beta kernel: [714136.025497] FS: 00007fc95d227740(0000) GS:ffff88003fd00000(0000) knlGS:0000000000000000
Aug 19 22:52:06 beta kernel: [714136.025572] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Aug 19 22:52:06 beta kernel: [714136.025634] CR2: 0000000000000038 CR3: 0000000017d43000 CR4: 00000000000406e0
Aug 19 22:52:06 beta kernel: [714136.025794] Stack:
Aug 19 22:52:06 beta kernel: [714136.025837] 000000000000000a ffff88003503d0a0 ffff880008b87d08 ffffffff81391843
Aug 19 22:52:06 beta kernel: [714136.025916] 000000013475e830 ffff88000000000a ffff88003503d050 ffff88003c0a8760
Aug 19 22:52:06 beta kernel: [714136.025994] ffff88003b6f4cc8 ffff88003503d000 ffff88003b6f4cc0 ffff880008b87d98
Aug 19 22:52:06 beta kernel: [714136.026072] Call Trace:
Aug 19 22:52:06 beta kernel: [714136.027329] [<ffffffff81391843>] aa_vec_unique+0x163/0x240
Aug 19 22:52:06 beta kernel: [714136.028403] [<ffffffff81395ab7>] __aa_labelset_update_subtree+0x687/0x820
Aug 19 22:52:06 beta kernel: [714136.029473] [<ffffffff8138897b>] aa_replace_profiles+0x59b/0xb70
Aug 19 22:52:06 beta kernel: [714136.030541] [<ffffffff811ecf4e>] ? __kmalloc+0x22e/0x250
Aug 19 22:52:06 beta kernel: [714136.031622] [<ffffffff8137d69f>] policy_update+0x9f/0x1f0
Aug 19 22:52:06 beta kernel: [714136.032684] [<ffffffff8137d803>] profile_replace+0x13/0x20
Aug 19 22:52:06 beta kernel: [714136.033699] [<ffffffff8120c9d8>] __vfs_write+0x18/0x40
Aug 19 22:52:06 beta kernel: [714136.034714] [<ffffffff8120d369>] vfs_write+0xa9/0x1a0
Aug 19 22:52:06 beta kernel: [714136.035728] [<ffffffff8120c2ff>] ? do_sys_open+0x1bf/0x2a0
Aug 19 22:52:06 beta kernel: [714136.036643] [<ffffffff8120e025>] SyS_write+0x55/0xc0
Aug 19 22:52:06 beta kernel: [714136.037570] [<ffffffff8182def2>] entry_SYSCALL_64_fastpath+0x16/0x71
Aug 19 22:52:06 beta kernel: [714136.038633] Code: 00 55 48 85 ff 48 89 e5 41 54 53 49 89 f4 48 89 fb 0f 84 8b 00 00 00 4d 85 e4 0f 84 aa 00 00 00 48 83 7b 38 00 0f 84 c9 00 00 00 <49> 83 7c 24 38 00 0f 84 e8 00 00 00 48 83 7b 08 00 0f 84 07 01
Aug 19 22:52:06 beta kernel: [714136.041564] RIP [<ffffffff8139066f>] profile_cmp+0x2f/0x180
Aug 19 22:52:06 beta kernel: [714136.042473] RSP <ffff880008b87cb0>
Aug 19 22:52:06 beta kernel: [714136.043290] CR2: 0000000000000038
Aug 19 22:52:06 beta kernel: [714136.045634] ---[ end trace 9f21e4366b6b8d2e ]---

# ps -ef | grep dpkg
root 9208 1 0 22:52 ? 00:00:00 /usr/bin/dpkg --status-fd 41 --configure apparmor:amd64
root 9209 9208 0 22:52 ? 00:00:00 /usr/bin/perl -w /usr/share/debconf/frontend /var/lib/dpkg/info/apparmor.postinst configure 2.10.95-0ubuntu2
root 9216 9209 0 22:52 ? 00:00:00 /bin/sh /var/lib/dpkg/info/apparmor.postinst configure 2.10.95-0ubuntu2

[Jonas Holmgren (islebranch)]

This will leave apparmor in a "half configured" state, which means that the kernel would crash next time the system is patched. To circumvent this problem, comment out the following line in /var/lib/dpkg/info/apparmor.postinst:
#load_configured_profiles || true

and finish the upgrade

# apt-get upgrade apparmor
-or-
# dpkg --configure -a

depending on the system's state.

I don't know what side effects this may cause, though.

PS. disabling all profiles does not prevent the kernel from crashing, so the profiles themselves are evidently not the problem.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[John Johansen (jjohansen)]

Profile state should never crash apparmor.

The userspace no matter it state should never be able to crash the kernel. Profiles go through a verification process before the kernel will make them available.

The "half" configured state may mean that not all apparmor profiles are loaded, or that some of the userspace functions aren't available but that should never result in a kernel oops.

The userspace obviously got far enough along to replace some policy and from the kernel trace we can see that apparmor oopsed during profile replacement, after the profile has been verified and it is being activated kernel side.

I believe this bug is already fixed by commit
57d3b8969c47b1dabeb9d122a88df2c14d4f1b9f UBUNTU: SAUCE: apparmor: fix vec_unique for vectors larger than 8

which was released in Ubuntu-4.4.0-37.56

[John Johansen (jjohansen)]

can you please test with a kernel that is Ubuntu-4.4.0-37.56 or later

[Launchpad Janitor (janitor)]

[Expired for apparmor (Ubuntu) because there has been no activity for 60 days.]