Comment 6 for bug 549428

Revision history for this message
petdog (petdog) wrote :

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 slab_reclaimable:224kB slab_unreclaimable:8kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1138562.401587] lowmem_reserve[]: 0 2958 3905 3905
[1138562.401599] Node 0 DMA32 free:21348kB min:6044kB low:7552kB high:9064kB active_anon:974156kB inactive_anon:263260kB active_file:572620kB inactive_file:888084kB unevictable:32kB isolated(anon):0kB isolated(file):544kB present:3029636kB mlocked:32kB dirty:5072kB writeback:0kB mapped:81636kB shmem:175948kB slab_reclaimable:141856kB slab_unreclaimable:62984kB kernel_stack:976kB pagetables:18592kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1138562.401625] lowmem_reserve[]: 0 0 946 946
[1138562.401635] Node 0 Normal free:3276kB min:1932kB low:2412kB high:2896kB active_anon:182296kB inactive_anon:209616kB active_file:71264kB inactive_file:69476kB unevictable:16kB isolated(anon):0kB isolated(file):0kB present:969600kB mlocked:16kB dirty:152kB writeback:0kB mapped:58652kB shmem:122692kB slab_reclaimable:15236kB slab_unreclaimable:34204kB kernel_stack:2280kB pagetables:22480kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1138562.401661] lowmem_reserve[]: 0 0 0 0
[1138562.401671] Node 0 DMA: 0*4kB 2*8kB 1*16kB 4*32kB 4*64kB 1*128kB 3*256kB 2*512kB 3*1024kB 3*2048kB 1*4096kB = 15648kB
[1138562.401696] Node 0 DMA32: 1839*4kB 293*8kB 136*16kB 220*32kB 6*64kB 2*128kB 1*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 21348kB
[1138562.401720] Node 0 Normal: 593*4kB 31*8kB 1*16kB 0*32kB 2*64kB 0*128kB 2*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3276kB
[1138562.401743] 475038 total pagecache pages
[1138562.401747] 0 pages in swap cache
[1138562.401753] Swap cache stats: add 54728, delete 54728, find 83949/85128
[1138562.401758] Free swap = 0kB
[1138562.401761] Total swap = 0kB
[1138562.442506] 1032192 pages RAM
[1138562.442511] 44196 pages reserved
[1138562.442515] 442162 pages shared
[1138562.442519] 703082 pages non-shared
[1138562.444565] type=1505 audit(1270041416.235:60): operation="profile_replace" pid=26793 name="/usr/bin/evince"
[1138562.455414] type=1505 audit(1270041416.245:61): operation="profile_replace" pid=26793 name="/usr/bin/evince-previewer"
[1138562.459073] type=1505 audit(1270041416.245:62): operation="profile_replace" pid=26793 name="/usr/bin/evince-thumbnailer"
[1138562.516253] type=1505 audit(1270041416.305:63): operation="profile_load" pid=26795 name="/usr/lib/firefox-3.7a3pre/firefox{,*[^s][^h]}"
[1138600.751741] __ratelimit: 15 callbacks suppressed
[1138600.751748] type=1505 audit(1270041454.544:69): operation="profile_replace" pid=26827 name="/usr/share/gdm/guest-session/Xsession"
[1138635.007138] type=1505 audit(1270041488.795:70): operation="profile_replace" pid=26837 name="/sbin/dhclient3"
[1138635.007380] type=1505 audit(1270041488.795:71): operation="profile_replace" pid=26837 name="/usr/lib/NetworkManager/nm-dhcp-client.action"
[1138635.007548] type=1505 audit(1270041488.795:72): operation="profile_replace" pid=26837 name="/usr/lib/connman/scripts/dhclient-script"
[1138641.200432] type=1505 audit(1270041494.985:73): operation="profile_replace" pid=26843 name="/usr/bin/evince"
[1138641.202107] type=1505 audit(1270041494.995:74): operation="profile_replace" pid=26843 name="/usr/bin/evince-previewer"
[1138641.203564] type=1505 audit(1270041494.995:75): operation="profile_replace" pid=26843 name="/usr/bin/evince-thumbnailer"
[1138643.522317] type=1505 audit(1270041497.314:76): operation="profile_replace" pid=26857 name="/usr/lib/firefox-3.7a3pre/firefox{,*[^s][^h]}"
[1138645.187709] type=1505 audit(1270041498.974:77): operation="profile_replace" pid=26863 name="/usr/lib/cups/backend/cups-pdf"
[1138645.187845] type=1505 audit(1270041498.974:78): operation="profile_replace" pid=26863 name="/usr/sbin/cupsd"
[1138646.801729] type=1505 audit(1270041500.594:79): operation="profile_replace" pid=26866 name="/usr/sbin/mysqld-akonadi"
[1138653.180926] type=1505 audit(1270041506.974:80): operation="profile_replace" pid=26923 name="/usr/sbin/named"
[1138657.904154] type=1505 audit(1270041511.694:81): operation="profile_replace" pid=26924 name="/usr/sbin/tcpdump"
[1138703.573151] type=1505 audit(1270041557.365:82): operation="profile_remove" pid=26977 name="/usr/lib/firefox-3.7a3pre/firefox{,*[^s][^h]}" namespace="root"