Triggers permanent high i/o load after upgrade

[Loïc Minier]

Binary package hint: apparmor

Hi

So this is the second time this happens after an upgrade of my laptop: i run a package upgrade using aptitude, and when it's done, some background I/O is happening after completion. This I/O never ends. The first time this happened was on 2010/03/09 after my morning upgrade; list of packages upgraded from aptitude.log:
mar., mars 9 2010 10:32:47 +0100

IMPORTANT : ce journal ne contient que les actions demandées ; certaines actions qui
échouent à cause d'erreurs de dpkg peuvent donc ne pas être réalisées.

90 paquets vont être installés, et 2 retirés.
893ko d'espace disque vont être utilisés
===============================================================================
[SUPPRIMÉ, NON UTILISÉ] libparted-2.1-0
[SUPPRIMÉ, NON UTILISÉ] libparted1.8-12
[INSTALLÉ, DÉPENDANCES] libaio1
[INSTALLÉ, DÉPENDANCES] libparted0
[MIS A JOUR] apparmor 2.5~pre+bzr1364-0ubuntu1 -> 2.5~pre+bzr1367-0ubuntu1
[MIS A JOUR] apparmor-utils 2.5~pre+bzr1364-0ubuntu1 -> 2.5~pre+bzr1367-0ubuntu1
[MIS A JOUR] apturl 0.4.1ubuntu2 -> 0.4.1ubuntu3
[MIS A JOUR] apturl-common 0.4.1ubuntu2 -> 0.4.1ubuntu3
[MIS A JOUR] at-spi 1.29.90-0ubuntu2 -> 1.29.92-0ubuntu1
[MIS A JOUR] binutils 2.20.1-1ubuntu1 -> 2.20.1-2ubuntu1
[MIS A JOUR] binutils-doc 2.20.1-1ubuntu1 -> 2.20.1-2ubuntu1
[MIS A JOUR] binutils-static 2.20.1-1ubuntu1 -> 2.20.1-2ubuntu1
[MIS A JOUR] empathy 2.29.91.2-0ubuntu1 -> 2.29.91.2-0ubuntu2
[MIS A JOUR] empathy-common 2.29.91.2-0ubuntu1 -> 2.29.91.2-0ubuntu2
[MIS A JOUR] euca2ools 1.2-0ubuntu5 -> 1.2-0ubuntu6
[MIS A JOUR] evince 2.29.91-0ubuntu1 -> 2.29.91-0ubuntu2
[MIS A JOUR] firefox 3.6+nobinonly-0ubuntu5 -> 3.6+nobinonly-0ubuntu6
[MIS A JOUR] firefox-branding 3.6+nobinonly-0ubuntu5 -> 3.6+nobinonly-0ubuntu6
[MIS A JOUR] firefox-gnome-support 3.6+nobinonly-0ubuntu5 -> 3.6+nobinonly-0ubuntu6
[MIS A JOUR] gbrainy 1.30-1ubuntu5 -> 1.40-1ubuntu1
[MIS A JOUR] gcalctool 5.29.92~20100301.2-0ubuntu1 -> 5.29.92-0ubuntu1
[MIS A JOUR] gnome-about 1:2.29.91-0ubuntu1 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] gnome-accessibility-themes 2.29.91-0ubuntu1 -> 2.29.92-0ubuntu1
[MIS A JOUR] gnome-desktop-data 1:2.29.91-0ubuntu1 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] gnome-menus 2.29.91-0ubuntu2 -> 2.29.92-0ubuntu2
[MIS A JOUR] gnome-themes-selected 2.29.91-0ubuntu1 -> 2.29.92-0ubuntu1
[MIS A JOUR] gstreamer0.10-alsa 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gstreamer0.10-ffmpeg 0.10.9.3-1 -> 0.10.10-1
[MIS A JOUR] gstreamer0.10-gnomevfs 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gstreamer0.10-plugins-base 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gstreamer0.10-plugins-base-apps 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gstreamer0.10-plugins-ugly 0.10.13.3-1 -> 0.10.14-1
[MIS A JOUR] gstreamer0.10-tools 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gstreamer0.10-x 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] gvfs 1.5.4-0ubuntu1 -> 1.5.5-0ubuntu1
[MIS A JOUR] gvfs-backends 1.5.4-0ubuntu1 -> 1.5.5-0ubuntu1
[MIS A JOUR] gvfs-bin 1.5.4-0ubuntu1 -> 1.5.5-0ubuntu1
[MIS A JOUR] gvfs-fuse 1.5.4-0ubuntu1 -> 1.5.5-0ubuntu1
[MIS A JOUR] humanity-icon-theme 0.5.1.2 -> 0.5.1.3
[MIS A JOUR] libapparmor-perl 2.5~pre+bzr1364-0ubuntu1 -> 2.5~pre+bzr1367-0ubuntu1
[MIS A JOUR] libapparmor1 2.5~pre+bzr1364-0ubuntu1 -> 2.5~pre+bzr1367-0ubuntu1
[MIS A JOUR] libatk1.0-0 1.29.4-0ubuntu1 -> 1.29.92-0ubuntu1
[MIS A JOUR] libatk1.0-data 1.29.4-0ubuntu1 -> 1.29.92-0ubuntu1
[MIS A JOUR] libatk1.0-doc 1.29.4-0ubuntu1 -> 1.29.92-0ubuntu1
[MIS A JOUR] libatspi1.0-0 1.29.90-0ubuntu2 -> 1.29.92-0ubuntu1
[MIS A JOUR] libcap2 1:2.17-2 -> 1:2.17-2ubuntu1
[MIS A JOUR] libcap2-bin 1:2.17-2 -> 1:2.17-2ubuntu1
[MIS A JOUR] libevdocument2 2.29.91-0ubuntu1 -> 2.29.91-0ubuntu2
[MIS A JOUR] libevview2 2.29.91-0ubuntu1 -> 2.29.91-0ubuntu2
[MIS A JOUR] libglib2.0-0 2.23.4-1ubuntu1 -> 2.23.4-1ubuntu2
[MIS A JOUR] libglib2.0-data 2.23.4-1ubuntu1 -> 2.23.4-1ubuntu2
[MIS A JOUR] libglib2.0-dev 2.23.4-1ubuntu1 -> 2.23.4-1ubuntu2
[MIS A JOUR] libglib2.0-doc 2.23.4-1ubuntu1 -> 2.23.4-1ubuntu2
[MIS A JOUR] libgnome-desktop-2-17 1:2.29.91-0ubuntu1 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] libgnome-menu2 2.29.91-0ubuntu2 -> 2.29.92-0ubuntu2
[MIS A JOUR] libgstreamer-plugins-base0.10-0 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] libgstreamer0.10-0 0.10.26.3-1 -> 0.10.27-1
[MIS A JOUR] libgvfscommon0 1.5.4-0ubuntu1 -> 1.5.5-0ubuntu1
[MIS A JOUR] libnautilus-extension1 1:2.29.91-0ubuntu2 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] libsmbclient 2:3.4.6~dfsg-1ubuntu1 -> 2:3.4.6~dfsg-1ubuntu2
[MIS A JOUR] libtaglib2.0-cil 2.0.3.4+dfsg-2 -> 2.0.3.6+dfsg-1
[MIS A JOUR] libvirt-bin 0.7.5-5ubuntu10 -> 0.7.5-5ubuntu12
[MIS A JOUR] libvirt0 0.7.5-5ubuntu10 -> 0.7.5-5ubuntu12
[MIS A JOUR] libwbclient0 2:3.4.6~dfsg-1ubuntu1 -> 2:3.4.6~dfsg-1ubuntu2
[MIS A JOUR] nautilus 1:2.29.91-0ubuntu2 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] nautilus-data 1:2.29.91-0ubuntu2 -> 1:2.29.92-0ubuntu1
[MIS A JOUR] openssh-client 1:5.3p1-3ubuntu2 -> 1:5.3p1-3ubuntu3
[MIS A JOUR] openssh-server 1:5.3p1-3ubuntu2 -> 1:5.3p1-3ubuntu3
[MIS A JOUR] parted 2.1-4ubuntu1 -> 2.2-1ubuntu2
[MIS A JOUR] pidgin-libnotify 0.14-1ubuntu13 -> 0.14-1ubuntu14
[MIS A JOUR] python-gmenu 2.29.91-0ubuntu2 -> 2.29.92-0ubuntu2
[MIS A JOUR] python-gtkspell 2.25.3-4.1ubuntu1 -> 2.25.3-4.1ubuntu2
[MIS A JOUR] python-libvirt 0.7.5-5ubuntu10 -> 0.7.5-5ubuntu12
[MIS A JOUR] python-pyatspi 1.29.90-0ubuntu2 -> 1.29.92-0ubuntu1
[MIS A JOUR] qemu-arm-static 0.12.3-0ubuntu10 -> 0.12.3-0ubuntu11
[MIS A JOUR] qemu-kvm 0.12.3-0ubuntu10 -> 0.12.3-0ubuntu11
[MIS A JOUR] qemu-kvm-extras 0.12.3-0ubuntu10 -> 0.12.3-0ubuntu11
[MIS A JOUR] qemu-kvm-extras-static 0.12.3-0ubuntu10 -> 0.12.3-0ubuntu11
[MIS A JOUR] samba-common 2:3.4.6~dfsg-1ubuntu1 -> 2:3.4.6~dfsg-1ubuntu2
[MIS A JOUR] samba-common-bin 2:3.4.6~dfsg-1ubuntu1 -> 2:3.4.6~dfsg-1ubuntu2
[MIS A JOUR] simple-scan 0.9.6-1ubuntu1 -> 0.9.7-0ubuntu1
[MIS A JOUR] smbclient 2:3.4.6~dfsg-1ubuntu1 -> 2:3.4.6~dfsg-1ubuntu2
[MIS A JOUR] ssh-askpass-gnome 1:5.3p1-3ubuntu2 -> 1:5.3p1-3ubuntu3
[MIS A JOUR] telepathy-haze 0.3.3-1 -> 0.3.4-1
[MIS A JOUR] udisks 1.0.0~git20100227.36c8a4-1 -> 1.0.0~git20100305.fa313b2-1ubuntu1
[MIS A JOUR] update-manager 1:0.132.1 -> 1:0.133
[MIS A JOUR] update-manager-core 1:0.132.1 -> 1:0.133
[MIS A JOUR] vim 2:7.2.245-2ubuntu3 -> 2:7.2.330-1ubuntu2
[MIS A JOUR] vim-common 2:7.2.245-2ubuntu3 -> 2:7.2.330-1ubuntu2
[MIS A JOUR] vim-runtime 2:7.2.245-2ubuntu3 -> 2:7.2.330-1ubuntu2
[MIS A JOUR] vim-tiny 2:7.2.245-2ubuntu3 -> 2:7.2.330-1ubuntu2
[MIS A JOUR] watershed 4build1 -> 5
===============================================================================

I couldn't find the source of the I/O in top or iotop; either it was in the kernel or it was spread on many processes.
I asked for some help diagnosing it on irc:
11:47 < lool> Something is adding massive load to my laptop since the latest upgrade
11:47 < lool> I can't figure out what it is; I see one of my CPU is busy in kernel space
11:47 < lool> iotop shows nothing (nor top obviously)
11:48 < lool> I have a long list of console-kit processes though

I ended up rebooting.

This happened yesterday evening again; much shorter upgrade log:
ven., mars 26 2010 23:36:36 +0100

IMPORTANT : ce journal ne contient que les actions demandées ; certaines actions qui
échouent à cause d'erreurs de dpkg peuvent donc ne pas être réalisées.

41 paquets vont être installés, et 1 retirés.
1 122ko d'espace disque vont être utilisés
===============================================================================
[SUPPRIMÉ, NON UTILISÉ] libntfs-3g54
[INSTALLÉ, DÉPENDANCES] libntfs-3g75
[MIS A JOUR] apparmor 2.5-0ubuntu1 -> 2.5-0ubuntu2
[MIS A JOUR] apparmor-utils 2.5-0ubuntu1 -> 2.5-0ubuntu2
[MIS A JOUR] apt 0.7.25.3ubuntu3 -> 0.7.25.3ubuntu4
[MIS A JOUR] apt-transport-https 0.7.25.3ubuntu3 -> 0.7.25.3ubuntu4
[MIS A JOUR] apt-utils 0.7.25.3ubuntu3 -> 0.7.25.3ubuntu4
[MIS A JOUR] apt-xapian-index 0.22 -> 0.25
[MIS A JOUR] capplets-data 1:2.29.92-0ubuntu2 -> 1:2.29.92-0ubuntu3
[MIS A JOUR] console-setup 1.34ubuntu12 -> 1.34ubuntu13
[MIS A JOUR] gnome-control-center 1:2.29.92-0ubuntu2 -> 1:2.29.92-0ubuntu3
[MIS A JOUR] gnome-power-manager 2.29.91-0ubuntu8 -> 2.29.91-0ubuntu9
[MIS A JOUR] indicator-session 0.2.7-0ubuntu2 -> 0.2.7-0ubuntu3
[MIS A JOUR] initramfs-tools 0.92bubuntu69 -> 0.92bubuntu71
[MIS A JOUR] initramfs-tools-bin 0.92bubuntu69 -> 0.92bubuntu71
[MIS A JOUR] jockey-common 0.5.8-0ubuntu3 -> 0.5.8-0ubuntu5
[MIS A JOUR] jockey-gtk 0.5.8-0ubuntu3 -> 0.5.8-0ubuntu5
[MIS A JOUR] language-selector 0.5.3 -> 0.5.4
[MIS A JOUR] language-selector-common 0.5.3 -> 0.5.4
[MIS A JOUR] libapparmor-perl 2.5-0ubuntu1 -> 2.5-0ubuntu2
[MIS A JOUR] libapparmor1 2.5-0ubuntu1 -> 2.5-0ubuntu2
[MIS A JOUR] libgnome-window-settings1 1:2.29.92-0ubuntu2 -> 1:2.29.92-0ubuntu3
[MIS A JOUR] libssl0.9.8 0.9.8k-7ubuntu6 -> 0.9.8k-7ubuntu7
[MIS A JOUR] light-themes 0.1.5.9 -> 0.1.6.0
[MIS A JOUR] ntfs-3g 1:2009.4.4-1ubuntu5 -> 1:2010.3.6-1ubuntu1
[MIS A JOUR] openssl 0.9.8k-7ubuntu6 -> 0.9.8k-7ubuntu7
[MIS A JOUR] python-cupshelpers 1.1.17+20100217-0ubuntu6 -> 1.1.17+20100217-0ubuntu9
[MIS A JOUR] python-distutils-extra 2.18 -> 2.18bzr1
[MIS A JOUR] python-software-properties 0.75.7 -> 0.75.8
[MIS A JOUR] python-twisted-bin 9.0.0-1 -> 10.0.0-2
[MIS A JOUR] python-twisted-core 9.0.0-1 -> 10.0.0-2
[MIS A JOUR] python-twisted-names 9.0.0-1 -> 10.0.0-1
[MIS A JOUR] python-twisted-web 9.0.0-1 -> 10.0.0-1
[MIS A JOUR] python-xkit 0.4.2 -> 0.4.2.1
[MIS A JOUR] software-properties-gtk 0.75.7 -> 0.75.8
[MIS A JOUR] sudo 1.7.2p1-1ubuntu3 -> 1.7.2p1-1ubuntu4
[MIS A JOUR] synaptic 0.63.1ubuntu1 -> 0.63.1ubuntu2
[MIS A JOUR] system-config-printer-common 1.1.17+20100217-0ubuntu6 -> 1.1.17+20100217-0ubuntu9
[MIS A JOUR] system-config-printer-gnome 1.1.17+20100217-0ubuntu6 -> 1.1.17+20100217-0ubuntu9
[MIS A JOUR] system-config-printer-udev 1.1.17+20100217-0ubuntu6 -> 1.1.17+20100217-0ubuntu7
[MIS A JOUR] ubuntu-mono 0.0.10 -> 0.0.11
[MIS A JOUR] valgrind 1:3.6.0~svn20100212-0ubuntu3 -> 1:3.6.0~svn20100212-0ubuntu4
===============================================================================

Since apparmor appears in both and probably impacts kernel-ish stuff too, I figured it could be the culprit, and hence I'm filing the bug here.

I couldn't find anything in syslog, kernel.log, dmesg (just the regular spam I get from other bugs).

I left my computer running all night, this morning I/O was still happening at a high rate (my disk activity LED was blinking fast as if doing lots of small I/O, my sysmon applet showed load and 100% CPU used in the system for one of my CPUs).

The next time this happens, I'll try echo-ing to /proc/sys/vm/block_dump to see where I/O is happening, but I wanted to report the bug as it seems like a serious one. I don't see anything special in my setup which would trigger this, it's quite boring. I have my /home on ecryptfs and am using LVM. The disk is a 120 GB SSD, so should have gone through any global file scan over night.

I couldn't reproduce the bug by dpkg-reconfiguring *apparmor*, jockey*, *ntfs*, apt-xapian-index nor by reinstalling them.

Bye,

ProblemType: Bug
ApparmorStatusOutput:
 Error: command /usr/sbin/apparmor_status failed with exit code 4: You do not have enough privilege to read the profile set.
 apparmor module is loaded.
Architecture: amd64
Date: Sat Mar 27 10:46:05 2010
DistroRelease: Ubuntu 10.04
Package: apparmor 2.5-0ubuntu2
ProcEnviron:
 LANGUAGE=fr_FR:fr:en_GB:en
 PATH=(custom, user)
 LANG=fr_FR.UTF-8
 SHELL=/bin/zsh
ProcVersionSignature: Ubuntu 2.6.32-17.26-generic 2.6.32.10+drm33.1
SourcePackage: apparmor
Uname: Linux 2.6.32-17-generic x86_64

[John Johansen (jjohansen)]

Loïc,

are you using auditd? If so can you attach output for /var/log/audit/audit.log
Also if you run into this again can you attach the output of aa_status.

[Loïc Minier (lool)]

I don't have any /var/log/audit*; I'll check aa_status next time this happens, thanks for the advice

[Loïc Minier (lool)]

Actually aa_status isn't on my system, is it still relevant

[John Johansen (jjohansen)]

Yes, it is part of the apparmor-utils package so it isn't a required part of the default install, you will need to run it as root to be able to collect as much information as possible. All the information collected by aa-status is available manually (its just raw in a raw form) if you don't want to or can't install apparmor-utils. via.
> sudo cat /sys/kernel/security/apparmor/profiles
> sudo ps auxZ

Another package you might consider installing is apparmor-notify which will give you gui notifications when apparmor is blocking access. If you do install it see man aa-notify for information on how to turn it on, as there is currently a bug where it isn't turned on by default when it is installed.

[petdog (petdog)]

I've seen this behaviour at least five times in the last month too; it probably happens when there's an apparmor upgrade. Both the cpu cores are in wait mode, the load average skyrockets to ~25 and the system becomes unusable. With some patience I usually switch to tty, login as root and kill some random stuff. Usually killing networkmanager and nm-applet brings things back to normal. One time I fixed it rmmod-ing and reloading 'iwlagn'.
Here's some junk from `dmesg` that probably explains it:

[1138553.650102] udev: starting version 151
[1138562.167699] type=1505 audit(1270041415.954:56): operation="profile_replace" pid=26791 name="/usr/share/gdm/guest-session/Xsession"
[1138562.177594] type=1505 audit(1270041415.964:57): operation="profile_replace" pid=26792 name="/sbin/dhclient3"
[1138562.179275] type=1505 audit(1270041415.964:58): operation="profile_replace" pid=26792 name="/usr/lib/NetworkManager/nm-dhcp-client.action"
[1138562.180189] type=1505 audit(1270041415.974:59): operation="profile_replace" pid=26792 name="/usr/lib/connman/scripts/dhclient-script"
[1138562.401339] apparmor_parser: page allocation failure. order:8, mode:0x40d0
[1138562.401349] Pid: 26793, comm: apparmor_parser Not tainted 2.6.32-16-generic #25-Ubuntu
[1138562.401356] Call Trace:
[1138562.401376] [<ffffffff810f742e>] __alloc_pages_slowpath+0x56e/0x580
[1138562.401386] [<ffffffff810f759e>] __alloc_pages_nodemask+0x15e/0x1a0
[1138562.401397] [<ffffffff8112a3d7>] alloc_pages_current+0x87/0xd0
[1138562.401405] [<ffffffff810f64ae>] __get_free_pages+0xe/0x50
[1138562.401413] [<ffffffff81133c4b>] __kmalloc+0x14b/0x1d0
[1138562.401426] [<ffffffff81279a62>] kvmalloc+0x22/0x40
[1138562.401434] [<ffffffff81279aee>] aa_simple_write_to_buffer+0x6e/0x140
[1138562.401446] [<ffffffff810397c9>] ? default_spin_lock_flags+0x9/0x10
[1138562.401454] [<ffffffff81279c41>] aa_profile_replace+0x21/0x60
[1138562.401464] [<ffffffff811400b8>] vfs_write+0xb8/0x1a0
[1138562.401472] [<ffffffff81140951>] sys_write+0x51/0x80
[1138562.401483] [<ffffffff810131f2>] system_call_fastpath+0x16/0x1b
[1138562.401488] Mem-Info:
[1138562.401492] Node 0 DMA per-cpu:
[1138562.401499] CPU 0: hi: 0, btch: 1 usd: 0
[1138562.401504] CPU 1: hi: 0, btch: 1 usd: 0
[1138562.401508] Node 0 DMA32 per-cpu:
[1138562.401514] CPU 0: hi: 186, btch: 31 usd: 0
[1138562.401520] CPU 1: hi: 186, btch: 31 usd: 0
[1138562.401524] Node 0 Normal per-cpu:
[1138562.401530] CPU 0: hi: 186, btch: 31 usd: 0
[1138562.401535] CPU 1: hi: 186, btch: 31 usd: 0
[1138562.401547] active_anon:289113 inactive_anon:118219 isolated_anon:0
[1138562.401550] active_file:160971 inactive_file:239394 isolated_file:136
[1138562.401552] unevictable:12 dirty:1306 writeback:0 unstable:0
[1138562.401555] free:10068 slab_reclaimable:39329 slab_unreclaimable:24299
[1138562.401557] mapped:35072 shmem:74660 pagetables:10268 bounce:0
[1138562.401563] Node 0 DMA free:15648kB min:28kB low:32kB high:40kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:16kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15304kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB sla...

[Loïc Minier (lool)]

The latest apparmor upgrade (2.5-0ubuntu3) didn't trigger this for me; it mentions:
  [ Kees Cook ]
  * debian/apparmor.functions: do not load in parallel, this is causing
    weird side-effects.

[Kees Cook (kees)]

We've seen several IO and memory pressure problems as a result of the parallel load. The true root cause is still unknown, but it seems that the parallel load makes it worse, so I've removed it for now.

[Loïc Minier (lool)]

So I hit this today, it looks like the same bug, but no apparmor update.

My system has permanent IO load, and all apps hit the disk hard whenever they do something.

sudo cat /sys/kernel/security/apparmor/profiles
/usr/sbin/tcpdump (enforce)
/usr/sbin/libvirtd (enforce)
/usr/sbin/cupsd (enforce)
/usr/lib/cups/backend/cups-pdf (enforce)
/usr/lib/libvirt/virt-aa-helper (enforce)
/usr/bin/evince-thumbnailer (enforce)
/usr/bin/evince-previewer (enforce)
/usr/bin/evince (enforce)
/usr/lib/connman/scripts/dhclient-script (enforce)
/usr/lib/NetworkManager/nm-dhcp-client.action (enforce)
/sbin/dhclient3 (enforce)
/usr/share/gdm/guest-session/Xsession (enforce)

aa-status reports similar output
apparmor module is loaded.
12 profiles are loaded.
12 profiles are in enforce mode.
   /sbin/dhclient3
   /usr/bin/evince
   /usr/bin/evince-previewer
   /usr/bin/evince-thumbnailer
   /usr/lib/NetworkManager/nm-dhcp-client.action
   /usr/lib/connman/scripts/dhclient-script
   /usr/lib/cups/backend/cups-pdf
   /usr/lib/libvirt/virt-aa-helper
   /usr/sbin/cupsd
   /usr/sbin/libvirtd
   /usr/sbin/tcpdump
   /usr/share/gdm/guest-session/Xsession
0 profiles are in complain mode.
3 processes have profiles defined.
3 processes are in enforce mode :
   /sbin/dhclient3 (7660)
   /usr/sbin/cupsd (1547)
   /usr/sbin/libvirtd (1331)
0 processes are in complain mode.
0 processes are unconfined but have a profile defined.

I wonder whether this is really apport; perhaps it's ecryptfs.

I did a sudo perf top, and got:
             3415.00 - 19.8% : read_hpet
             1398.00 - 8.1% : find_vma
             1151.00 - 6.7% : drm_clflush_pages [drm]
              948.00 - 5.5% : __ticket_spin_lock
              582.00 - 3.4% : rb_next
              334.00 - 1.9% : acpi_os_read_port
              290.00 - 1.7% : fget_light
              274.00 - 1.6% : page_check_address
              252.00 - 1.5% : schedule
              233.00 - 1.3% : copy_user_generic_string
              201.00 - 1.2% : kref_put
              199.00 - 1.2% : unix_poll
              182.00 - 1.1% : _spin_unlock_irqrestore
              177.00 - 1.0% : clear_page_c
              165.00 - 1.0% : kref_get

or is this drm? that sounds really heavy

[Kees Cook (kees)]

> I did a sudo perf top, and got:

Try catching it with latencytop? That's how I managed to isolate my ext4
umount issues.

[Loïc Minier (lool)]

So itseems it's some shortage of RAM somewhere:
I joined #ubuntu-kernel:
20:10 < lool> My kernel is doing stuff but I dont know what
20:10 < lool> and my machine is dying under background IO load
20:10 < lool> I tried sudo perf top, iotop, regular top, and can't tell what's
              happening
20:10 < lool> see bug #549428
20:10 < ubot3> Malone bug 549428 in apparmor "Triggers permanent high i/o load
               after upgrade" [Undecided,Fix committed]
               https://launchpad.net/bugs/549428
20:10 < lool> I get this regularly, but not daily
20:11 < lool> I will have to reboot the system pretty soon given that it's
              almost unusable now; anything I can do?
20:12 < lool> I don't know whether that's expected, but cat
              /sys/kernel/debug/dri/64/vma returns
20:12 < lool> cat: /sys/kernel/debug/dri/64/vma: Cannot allocate memory
20:13 < lool> sudo cat i915_ringbuffer_data
20:13 < lool> cat: i915_ringbuffer_data: Ne peut allouer de la mémoire
20:13 < lool> that sounds bad
20:13 < smb> At least like something went crazy requesting memory
20:14 < lool> oddly, meminfo lists plenty of cached stuff
20:14 < lool> Oh I know
20:14 < lool> So I'm using ecryptfs
20:14 < lool> and I use unison in the background
20:14 < lool> Every so many days, this starts happening
20:14 < lool> I bet it's not giving back some memory to the OS
20:14 < lool> smb: How could I track memory down?
20:15 < lool> http://paste.ubuntu.com/418779/ < meminfo
20:15 < lool> Cached: 2492220 kB
20:15 < smb> Maybe one could keep tracking memory allocation while running
20:15 < smb> apparently you cannot even look right now
20:15 < lool> smb: Well my system still runs for some rason
20:15 < lool> reason
20:15 < smb> A high cached value is normal
20:15 < lool> I suspect the background load is swapping
20:16 < lool> Except I dont have any hmm
20:16 < lool> smb: Yes, but I mean this should be reclaimable to allocate memory
20:16 < lool> smb: I would expect that if my kernel used all available mem,
              this value would be small
20:16 < lool> VmallocTotal: 34359738367 kB
20:16 < lool> VmallocChunk: 34359353372 kB
20:17 < lool> that's.... too much
20:17 < lool> I don't have 34 TB of vm
20:17 < lool> Hmm apparently that's normal
20:17 < lool> it matches another host
20:18 < lool> probably some addressable range
20:20 < smb> I would believe so
20:24 < smb> lool, The thing is that you seem to be unable to start new tasks
             which sounds like shortage of allocable memory
20:25 < lool> smb: I can actually start other tasks
20:25 < lool> Could at least
20:25 < lool> smb: I could open an xterm for instance
20:25 < lool> albeit slowly

I suspect it's ecryptfs or drm; drm because it shows up frequently in perf top, and because cat on some /sys/kernel/debug files would fail before reboot and now works fine, but that could be due to memory having been eaten by someone else.
ecryptfs could be related because I see disk activity and because this would explain the delay before this happens; I run unison over a GB of data every 5 minutes, so that would expose a memleak after a while.

[Loïc Minier (lool)]

Next time I hit this, I will try running latencytop, but I suspect I'm entering into a memory pressure situation and latencytop might show the results of the pressured system, but not the reason for the pressure :-/

[Loïc Minier (lool)]

I'm moving this bug to linux, as I didn't see any improvements with the uploaded patches and I'm not really sure it's apparmor related anymore, or perhaps multiple issues were conflated in one.

[Dustin Kirkland  (kirkland)]

Tyler-

I subscribed you to this bug.

Loic is seeing an abnormally high IO load on his system, which is using eCryptfs for his $HOME. He's thinking there might be a memory leak somewhere, perhaps?

Can you offer any pointers as to how to debug this? Tools you might use to profile or instrument this sort of thing?

[Loïc Minier (lool)]

Looks like I got hit by bug #565981; not clear how many bugs affected my system here though.

[Jamie Strandboge (jdstrand)]

Loic, based on your comments, it is believed the remaining memory pressure issue may be bug #565981. Marking as a duplicate for now. If you find this is in error, please feel free to adjust this bug accordingly.