Re: sid kernel slower than squeeze
Hi Ben,
Thanks for the tips. In watching the uptime on the 3.2.0 machine, I've
noticed that it's like a wave, on an approximate cycle of a minute, sometimes
more, where the load dips to 0.16 or so, and then quickly spikes to 0.50
and sometimes 0.80, with very little load otherwise.
Below is the top output from the machine, running kernel 3.2.0. You can see
that the trailing load number is about 0.57. The lowest I've seen that
number is 0.49. On the 2.6.32 kernel, after waiting about 15 minutes, it
drops to about 0.10, and would probably go lower in time.
top - 17:16:51 up 34 min, 5 users, load average: 0.32, 0.48, 0.57
Tasks: 114 total, 1 running, 113 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.8 us, 0.8 sy, 0.0 ni, 81.3 id, 16.2 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem: 1025856 total, 632808 used, 393048 free, 22924 buffers
KiB Swap: 530428 total, 0 used, 530428 free, 448052 cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3669 root 20 0 4492 1216 956 R 6.2 0.1 0:00.01 top
1 root 20 0 2256 704 604 S 0.0 0.1 0:00.98 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root 20 0 0 0 0 S 0.0 0.0 0:00.18 ksoftirqd/0
6 root rt 0 0 0 0 S 0.0 0.0 0:00.00 migration/0
7 root rt 0 0 0 0 S 0.0 0.0 0:00.00 watchdog/0
8 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 cpuset
9 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 khelper
10 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
11 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 netns
12 root 20 0 0 0 0 S 0.0 0.0 0:00.00 sync_supers
13 root 20 0 0 0 0 S 0.0 0.0 0:00.00 bdi-default
14 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kintegrityd
15 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kblockd
17 root 20 0 0 0 0 S 0.0 0.0 0:00.00 khungtaskd
18 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kswapd0
19 root 25 5 0 0 0 S 0.0 0.0 0:00.00 ksmd
20 root 39 19 0 0 0 S 0.0 0.0 0:00.00 khugepaged
21 root 20 0 0 0 0 S 0.0 0.0 0:00.00 fsnotify_mark
22 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 crypto
25 root 20 0 0 0 0 S 0.0 0.0 0:00.80 kworker/0:2
99 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 firewire
100 root 20 0 0 0 0 S 0.0 0.0 0:00.00 khubd
137 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 ata_sff
138 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kworker/u:1
147 root 20 0 0 0 0 S 0.0 0.0 0:00.01 scsi_eh_0
148 root 20 0 0 0 0 S 0.0 0.0 0:00.20 scsi_eh_1
149 root 20 0 0 0 0 S 0.0 0.0 0:00.02 kworker/u:2
179 root 20 0 0 0 0 S 0.0 0.0 0:00.08 kjournald
305 root 20 0 2908 1468 732 S 0.0 0.1 0:00.11 udevd
412 root 20 0 2904 1204 460 S 0.0 0.1 0:00.00 udevd
413 root 20 0 2904 1152 412 S 0.0 0.1 0:00.00 udevd
445 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kpsmoused
447 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 cfg80211
450 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 r852
452 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 kmemstick
453 root 20 0 0 0 0 S 0.0 0.0 0:00.00 r592_io
486 root 0 -20 0 0 0 S 0.0 0.0 0:00.00 hd-audio0
1801 root 20 0 28048 1632 1028 S 0.0 0.2 0:00.15 rsyslogd
1836 root 20 0 0 0 0 S 0.0 0.0 0:00.03 flush-8:0
1837 messageb 20 0 3812 1856 880 S 0.0 0.2 0:00.81 dbus-daemon
1862 root 20 0 1852 596 484 S 0.0 0.1 0:00.00 acpid
1887 root 20 0 26640 5424 4556 S 0.0 0.5 0:00.45 NetworkManager
1917 root 20 0 24276 3928 2768 S 0.0 0.4 0:00.79 polkitd
1921 root 20 0 6848 2696 2196 S 0.0 0.3 0:00.03 modem-manager
1924 root 20 0 5792 2568 2184 S 0.0 0.3 0:00.08 wpa_supplicant
1932 root 20 0 17984 2852 2416 S 0.0 0.3 0:00.02 gdm3
1961 root 20 0 5164 3036 1312 S 0.0 0.3 0:00.00 dhclient
1965 avahi 20 0 3124 1440 1208 S 0.0 0.1 0:00.07 avahi-daemon
1966 avahi 20 0 3124 428 216 S 0.0 0.0 0:00.00 avahi-daemon
1985 root 20 0 20308 3720 3088 S 0.0 0.4 0:00.03 gdm-simple-slav
1994 root 20 0 4456 1360 1164 S 0.0 0.1 0:00.00 bluetoothd
2004 root 10 -10 0 0 0 S 0.0 0.0 0:00.00 krfcommd
2049 root 20 0 58724 8828 4520 S 0.0 0.9 0:03.46 Xorg
2051 root 20 0 3812 924 744 S 0.0 0.1 0:00.00 cron
2233 root 20 0 6440 1592 1152 S 0.0 0.2 0:00.00 sshd
2258 root 20 0 1824 440 368 S 0.0 0.0 0:00.05 minissdpd
2267 root 20 0 3756 832 708 S 0.0 0.1 0:00.00 getty
2268 root 20 0 3756 836 708 S 0.0 0.1 0:00.02 getty
2269 root 20 0 3756 848 708 S 0.0 0.1 0:00.00 getty
2270 root 20 0 3756 848 708 S 0.0 0.1 0:00.00 getty
2271 root 20 0 3756 832 708 S 0.0 0.1 0:00.00 getty
2272 root 20 0 3756 836 708 S 0.0 0.1 0:00.00 getty
2282 root 20 0 26956 3416 2716 S 0.0 0.3 0:00.23 console-kit-dae
2373 root 20 0 26560 4112 3208 S 0.0 0.4 0:00.69 upowerd
2392 root 20 0 9880 3312 2640 S 0.0 0.3 0:00.13 sshd
2513 rtkit 21 1 18948 1196 1016 S 0.0 0.1 0:00.02 rtkit-daemon
2519 cdfrey 20 0 9880 1988 1312 S 0.0 0.2 0:00.29 sshd
2520 cdfrey 20 0 4692 1860 1500 S 0.0 0.2 0:00.13 bash
2535 colord 20 0 42128 7816 6188 S 0.0 0.8 0:00.38 colord-sane
2550 root 20 0 26796 3944 3296 S 0.0 0.4 0:00.11 gdm-session-wor
2553 root 20 0 22332 3052 2616 S 0.0 0.3 0:00.06 accounts-daemon
2572 cdfrey 20 0 75668 3564 3028 S 0.0 0.3 0:00.03 gnome-keyring-d
2574 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kauditd
2590 cdfrey 20 0 48940 9040 7224 S 0.0 0.9 0:00.23 x-session-manag
2630 cdfrey 20 0 3844 708 488 S 0.0 0.1 0:00.00 ssh-agent
2633 cdfrey 20 0 3496 512 320 S 0.0 0.0 0:00.00 dbus-launch
2634 cdfrey 20 0 4288 1660 748 S 0.0 0.2 0:00.17 dbus-daemon
2643 cdfrey 20 0 142m 16m 11m S 0.0 1.6 0:01.25 gnome-settings-
2656 cdfrey 20 0 8548 2260 1900 S 0.0 0.2 0:00.00 gvfsd
2662 cdfrey 9 -11 97404 5312 3860 S 0.0 0.5 0:00.18 pulseaudio
2668 cdfrey 20 0 46288 3828 3056 S 0.0 0.4 0:00.02 gsd-printer
2673 cdfrey 20 0 9420 3344 2748 S 0.0 0.3 0:00.03 gvfs-gdu-volume
2675 root 20 0 22980 3568 2924 S 0.0 0.3 0:00.14 udisks-daemon
2676 root 20 0 6312 716 456 S 0.0 0.1 0:00.14 udisks-daemon
2679 cdfrey 20 0 19056 2224 1832 S 0.0 0.2 0:00.08 gvfs-afc-volume
2682 cdfrey 20 0 8624 2108 1680 S 0.0 0.2 0:00.00 gvfs-gphoto2-vo
2684 colord 20 0 24520 4236 3492 S 0.0 0.4 0:00.03 colord
2689 cdfrey 20 0 498m 65m 38m S 0.0 6.5 0:12.94 gnome-shell
2702 cdfrey 20 0 63784 8232 4324 S 0.0 0.8 0:00.26 tracker-store
2703 cdfrey 20 0 46936 11m 8976 S 0.0 1.1 0:00.16 evolution-alarm
2705 cdfrey 20 0 130m 12m 9404 S 0.0 1.2 0:00.78 gnome-screensav
2707 cdfrey 20 0 8708 3008 1824 S 0.0 0.3 0:00.06 gconfd-2
2708 cdfrey 39 19 49064 7492 5636 S 0.0 0.7 0:00.17 tracker-miner-f
2709 cdfrey 20 0 24724 8248 6508 S 0.0 0.8 0:00.09 gdu-notificatio
2710 cdfrey 20 0 214m 12m 9.8m S 0.0 1.2 0:00.32 nm-applet
2716 cdfrey 20 0 30168 2348 2012 S 0.0 0.2 0:00.00 dconf-service
2744 cdfrey 20 0 47416 9520 7524 S 0.0 0.9 0:00.08 gnome-shell-cal
2748 cdfrey 20 0 36448 4984 4184 S 0.0 0.5 0:00.12 mission-control
2752 cdfrey 20 0 91832 9628 7552 S 0.0 0.9 0:00.07 goa-daemon
2788 cdfrey 20 0 277m 54m 26m S 0.0 5.4 0:02.73 iceape-bin
2828 cdfrey 20 0 149m 14m 10m S 0.0 1.4 0:00.87 gnome-terminal
2833 cdfrey 20 0 2056 712 580 S 0.0 0.1 0:00.00 gnome-pty-helpe
2834 cdfrey 20 0 4692 1808 1452 S 0.0 0.2 0:00.00 bash
2838 cdfrey 20 0 4692 1812 1452 S 0.0 0.2 0:00.00 bash
2941 root 20 0 9880 3312 2640 S 0.0 0.3 0:00.12 sshd
2946 cdfrey 20 0 9880 1988 1312 S 0.0 0.2 0:00.30 sshd
2947 cdfrey 20 0 4688 1820 1468 S 0.0 0.2 0:00.00 bash
2993 root 20 0 4744 1456 1128 S 0.0 0.1 0:00.08 su
3000 root 20 0 4724 1876 1484 S 0.0 0.2 0:00.10 bash
3622 cdfrey 20 0 4496 1396 984 S 0.0 0.1 0:00.74 top
3631 root 20 0 0 0 0 S 0.0 0.0 0:00.12 kworker/0:1
3657 root 20 0 46912 5592 4640 S 0.0 0.5 0:00.05 packagekitd
3666 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kworker/0:0
And here's the perf report during one of those upswings in load:
# ========
# captured on: Mon Jun 11 17:20:42 2012
# hostname : blowaway
# os release : 3.2.0-2-686-pae
# perf version : 3.2.7
# arch : i686
# nrcpus online : 1
# nrcpus avail : 1
# cpudesc : Intel(R) Pentium(R) M processor 1.73GHz
# cpuid : GenuineIntel,6,13,8
# total memory : 1025856 kB
# cmdline : /usr/bin/perf_3.2 record -a sleep 10
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 22 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# ========
#
# Events: 45 cycles
#
# Overhead Command Shared Object Symbol
# ........ ........... ....................... ...............................
#
39.72% swapper [processor] [k] acpi_idle_do_entry
17.53% swapper [kernel.kallsyms] [k] read_hpet
16.94% swapper [kernel.kallsyms] [k] hpet_next_event.isra.6
9.72% swapper [kernel.kallsyms] [k] acpi_os_read_port
4.05% gnome-shell libglib-2.0.so.0.3200.3 [.] g_variant_serialised_n_children
2.42% kworker/0:1 [kernel.kallsyms] [k] paravirt_read_tsc
1.47% gnome-shell libglib-2.0.so.0.3200.3 [.] g_slice_alloc
1.29% ksoftirqd/0 [kernel.kallsyms] [k] __schedule
1.21% scsi_eh_1 [kernel.kallsyms] [k] ioread8
1.21% kworker/0:3 [kernel.kallsyms] [k] ioread8
1.18% gnome-shell [kernel.kallsyms] [k] find_get_page
1.10% swapper [kernel.kallsyms] [k] ack_apic_level
1.06% gnome-shell [kernel.kallsyms] [k] __call_rcu
0.90% kworker/0:1 [kernel.kallsyms] [k] delay_tsc
0.21% sleep [kernel.kallsyms] [k] __init_rwsem
0.00% perf_3.2 [kernel.kallsyms] [k] native_write_msr_safe
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
And again:
# ========
# captured on: Mon Jun 11 17:22:52 2012
# hostname : blowaway
# os release : 3.2.0-2-686-pae
# perf version : 3.2.7
# arch : i686
# nrcpus online : 1
# nrcpus avail : 1
# cpudesc : Intel(R) Pentium(R) M processor 1.73GHz
# cpuid : GenuineIntel,6,13,8
# total memory : 1025856 kB
# cmdline : /usr/bin/perf_3.2 record -a sleep 10
# event : name = cycles, type = 0, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 24 }
# HEADER_CPU_TOPOLOGY info available, use -I to display
# ========
#
# Events: 126 cycles
#
# Overhead Command Shared Object Symbol
# ........ ............... ............................... ...................................
#
23.77% swapper [processor] [k] acpi_idle_do_entry
7.90% ksoftirqd/0 [kernel.kallsyms] [k] check_for_new_grace_period.isra.26
6.40% gnome-shell libc-2.13.so [.] 0x7d04c
5.52% NetworkManager libglib-2.0.so.0.3200.3 [.] g_hash_table_lookup
5.01% gnome-shell libmozjs185.so.1.0.0 [.] 0x9e85d
3.21% gnome-shell libgjs.so.0.0.0 [.] 0x2612d
2.32% gnome-shell libgobject-2.0.so.0.3200.3 [.] 0x2aba5
1.84% gnome-shell libxml2.so.2.8.0 [.] 0x329cf
1.76% kworker/0:1 [kernel.kallsyms] [k] paravirt_read_tsc
1.67% swapper [kernel.kallsyms] [k] read_hpet
1.57% gnome-shell libglib-2.0.so.0.3200.3 [.] g_strsplit
1.46% gnome-shell libglib-2.0.so.0.3200.3 [.] g_static_mutex_get_mutex_impl
1.45% gnome-shell [kernel.kallsyms] [k] find_vma
1.43% nm-applet libgtk-3.so.0.400.2 [.] 0x15d152
1.43% gnome-shell libgobject-2.0.so.0.3200.3 [.] g_signal_emit_by_name
1.43% gnome-shell libgirepository-1.0.so.1.0.0 [.] g_interface_info_find_method
1.41% gnome-shell libc-2.13.so [.] malloc
1.35% nm-applet libcairo.so.2.11200.2 [.] 0x4bc87
1.35% gnome-shell i915_dri.so [.] 0x1387d6
1.30% gnome-shell libcogl.so.9.1.1 [.] 0x3f5e0
1.28% gnome-shell libgnome-shell.so [.] st_box_layout_child_get_type
1.27% nm-applet [kernel.kallsyms] [k] walk_component
1.25% gnome-shell libclutter-1.0.so.0.1000.6 [.] clutter_paint_volume_union
1.23% Xorg [kernel.kallsyms] [k] hrtimer_forward
1.21% gnome-shell libgjs.so.0.0.0 [.] gjs_runtime_pop_context
1.20% gnome-shell libclutter-1.0.so.0.1000.6 [.] clutter_paint_volume_set_height
1.15% gnome-shell libgobject-2.0.so.0.3200.3 [.] g_type_interface_peek
1.12% gnome-shell libclutter-1.0.so.0.1000.6 [.] 0xc55fe
1.09% gnome-shell libclutter-1.0.so.0.1000.6 [.] clutter_actor_get_type
1.05% swapper [kernel.kallsyms] [k] arch_local_irq_restore
0.97% gnome-shell [kernel.kallsyms] [k] __blocking_notifier_call_chain
0.95% gnome-shell [kernel.kallsyms] [k] handle_pte_fault
0.90% gnome-shell [kernel.kallsyms] [k] free_pidmap
0.75% dbus-daemon dbus-daemon [.] 0x32401
0.69% scsi_eh_1 [kernel.kallsyms] [k] paravirt_read_tsc
0.67% swapper [i915] [k] i915_read32
0.65% scsi_eh_1 [kernel.kallsyms] [k] ioread8
0.56% swapper [kernel.kallsyms] [k] tick_handle_oneshot_broadcast
0.53% gnome-shell libgobject-2.0.so.0.3200.3 [.] g_param_spec_pool_lookup
0.49% gnome-shell libgobject-2.0.so.0.3200.3 [.] g_value_type_compatible
0.48% swapper [kernel.kallsyms] [k] clockevents_program_event
0.48% kjournald [kernel.kallsyms] [k] paravirt_read_tsc
0.37% nm-applet libdbus-glib-1.so.2.2.2 [.] 0x10311
0.35% swapper [processor] [k] acpi_idle_enter_bm
0.35% swapper [kernel.kallsyms] [k] acpi_os_write_port
0.35% swapper [kernel.kallsyms] [k] acpi_os_read_port
0.35% swapper [kernel.kallsyms] [k] acpi_hw_validate_io_request
0.35% swapper [ipw2200] [k] ipw_isr
0.32% swapper [ipw2200] [k] ipw_irq_tasklet
0.32% gnome-shell libc-2.13.so [.] free
0.32% mission-control libdbus-1.so.3.7.1 [.] 0x15840
0.31% swapper [kernel.kallsyms] [k] sched_clock_local
0.31% gnome-shell libpulse-mainloop-glib.so.0.0.4 [.] 0x1df3
0.28% swapper [kernel.kallsyms] [k] paravirt_read_tsc
0.28% gnome-shell libglib-2.0.so.0.3200.3 [.] 0x385a8
0.27% swapper [kernel.kallsyms] [k] hrtimer_force_reprogram
0.25% swapper [kernel.kallsyms] [k] acpi_hw_read_multiple
0.25% gnome-shell libglib-2.0.so.0.3200.3 [.] g_main_context_prepare
0.25% avahi-daemon [kernel.kallsyms] [k] sysenter_past_esp
0.25% Xorg [kernel.kallsyms] [k] do_select
0.25% NetworkManager NetworkManager [.] nm_device_wifi_get_ipw_rfkill_state
0.24% swapper [kernel.kallsyms] [k] ipv6_chk_mcast_addr
0.24% gnome-shell libgirepository-1.0.so.1.0.0 [.] g_typelib_symbol
0.10% sleep [kernel.kallsyms] [k] native_set_pud
0.00% perf_3.2 [kernel.kallsyms] [k] native_write_msr_safe
#
# (For a higher level overview, try: perf report --sort comm,dso)
#
- Chris
Reply to: