On Thu, Jul 28, 2011 at 04:51:24PM -0400, Chris Mason wrote: > Sorry, hit send too soon. Here is the latencytop patch, after you > recompile run latencytop -c for a few minutes. Send the output here. > > http://oss.oracle.com/~mason/latencytop.patch Ok, I ran it for more than a few minutes. Early on (shortly after boot), the output shows this for a long time: =============== Mon Aug 1 21:09:30 2011 Globals: Cause Maximum Percentage Process details: Process ksoftirqd/0 (3) Total: 3.9 msec [run_ksoftirqd] 3.9 msec 100.0 % run_ksoftirqd kthread kernel_thread_helper Process kworker/1:1 (983) Total: 31.2 msec . 3.9 msec 100.0 % worker_thread kthread kernel_thread_helper Process sshd (3948) Total: 3.9 msec Waiting for event (select) 3.9 msec 100.0 % poll_schedule_timeout do_select core_sys_select sys_select system_call_fastpath Process btrfs-cleaner (4345) Total: 2433.6 msec [sleep_on_page] 31.3 msec 100.0 % sleep_on_page wait_on_page_bit read_extent_buffer_pages btree_read_extent_buffer_pages read_tree_block read_block_for_search btrfs_search_slot lookup_inline_extent_backref __btrfs_free_extent run_clustered_refs btrfs_run_delayed_refs __btrfs_end_transaction Process btrfs-transacti (4346) Total: 2437.5 msec [sleep_on_page] 27.3 msec 100.0 % sleep_on_page wait_on_page_bit read_extent_buffer_pages btree_read_extent_buffer_pages read_tree_block read_block_for_search btrfs_search_slot lookup_inline_extent_backref __btrfs_free_extent run_clustered_refs btrfs_run_delayed_refs btrfs_commit_transaction This repeats identically (all numbers and backtrace is very stable) for a long time. Much later, I see this: =============== Tue Aug 2 13:46:29 2011 Globals: Cause Maximum Percentage Process details: Process btrfs-submit-0 (4332) Total: 199.2 msec Creating block layer request 58.6 msec 100.0 % get_request_wait __make_request generic_make_request submit_bio run_scheduled_bios pending_bios_fn worker_loop kthread kernel_thread_helper Process btrfs-cleaner (4345) Total: 3.9 msec Creating block layer request 3.9 msec 100.0 % get_request_wait __make_request generic_make_request submit_bio btrfs_map_bio btree_submit_bio_hook submit_one_bio read_extent_buffer_pages readahead_tree_block reada_walk_down do_walk_down walk_down_tree Process btrfs-endio-met (4700) Total: 35.2 msec [worker_loop] 3.9 msec 100.0 % worker_loop kthread kernel_thread_helper Process kworker/1:2 (26315) Total: 50.8 msec . 3.9 msec 100.0 % worker_thread kthread kernel_thread_helper [...snip...] =============== Thu Aug 4 12:34:08 2011 Globals: Cause Maximum Percentage Process details: Process btrfs-submit-0 (4332) Total: 199.2 msec Creating block layer request 58.6 msec 100.0 % get_request_wait __make_request generic_make_request submit_bio run_scheduled_bios pending_bios_fn worker_loop kthread kernel_thread_helper Process btrfs-cleaner (4345) Total: 3.9 msec Creating block layer request 3.9 msec 100.0 % get_request_wait __make_request generic_make_request submit_bio btrfs_map_bio btree_submit_bio_hook submit_one_bio read_extent_buffer_pages readahead_tree_block reada_walk_down do_walk_down walk_down_tree Process btrfs-endio-met (4700) Total: 35.2 msec [worker_loop] 3.9 msec 100.0 % worker_loop kthread kernel_thread_helper -- Bruce Guenter <bruce@xxxxxxxxxxxxxx> http://untroubled.org/
Attachment:
pgpt_PKwiBLgm.pgp
Description: PGP signature
