All of lore.kernel.org
 help / color / mirror / Atom feed
From: Ben Gamari <bgamari.foss@gmail.com>
To: linux-kernel@vger.kernel.org
Cc: tytso@mit.edu, npiggin@suse.de, mingo@elte.hu,
	Ruald Andreae <ruald.a@gmail.com>,
	Jens Axboe <jens.axboe@oracle.com>, Olly Betts <olly@survex.com>,
	martin f krafft <madduck@madduck.net>
Subject: Re: Poor interactive performance with I/O loads with fsync()ing
Date: Sat, 27 Mar 2010 18:29:14 -0700 (PDT)	[thread overview]
Message-ID: <4baeb0ea.9653f10a.4c8d.5d92@mx.google.com> (raw)
In-Reply-To: <4baeaee5.c5c2f10a.7187.2688@mx.google.com>

On Sat, 27 Mar 2010 18:20:37 -0700 (PDT), Ben Gamari <bgamari.foss@gmail.com> wrote:
> Hey all,
> 
> I have posted another profile[1] from an incident yesterday. As you can see,
> both swapper and init (strange?) show up prominently in the profile. Moreover,
> most processes seem to be in blk_peek_request a disturbingly large percentage
> of the time. Both of these profiles were taken with 2.6.34-rc kernels.
> 

Apparently my initial email announcing my first set of profiles never made it
out. Sorry for the confusion. I've included it below.


From: Ben Gamari <bgamari.foss@gmail.com>
Subject: Re: Poor interactive performance with I/O loads with fsync()ing
To: Ingo Molnar <mingo@elte.hu>, Nick Piggin <npiggin@suse.de>
Cc: tytso@mit.edu, linux-kernel@vger.kernel.org, Olly Betts
	<olly@survex.com>, martin f krafft <madduck@madduck.net>
Bcc: bgamari@gmail.com
In-Reply-To: <20100317093704.GA17146@elte.hu>
References: <4b9fa440.12135e0a.7fc8.ffffe745@mx.google.com>
	<20100317045350.GA2869@laptop> <20100317093704.GA17146@elte.hu>
On Wed, 17 Mar 2010 10:37:04 +0100, Ingo Molnar <mingo@elte.hu> wrote:
> A call-graph profile will show the precise reason for IO latencies, and their 
> relatively likelihood.

Well, here is something for now. I'm not sure how valid the reproduction
workload is (git pull, rsync, and 'notmuch new' all running at once), but I
certainly did produce a few stalls and swapper is highest on the profile.
This was on 2.6.34-rc2. I've included part of the profile below, although more
complete set of data is available at [1].

Thanks,

- Ben


[1] http://mw0.mooo.com/~ben/latency-2010-03-25-a/


# Samples: 25295
#
# Overhead          Command      Shared Object  Symbol
# ........  ...............  .................  ......
#
    24.50%          swapper  [kernel.kallsyms]  [k] blk_peek_request
                    |
                    --- blk_peek_request
                        scsi_request_fn
                        __blk_run_queue
                       |          
                       |--98.32%-- blk_run_queue
                       |          scsi_run_queue
                       |          scsi_next_command
                       |          scsi_io_completion
                       |          scsi_finish_command
                       |          scsi_softirq_done
                       |          blk_done_softirq
                       |          __do_softirq
                       |          call_softirq
                       |          do_softirq
                       |          irq_exit
                       |          |          
                       |          |--99.56%-- do_IRQ
                       |          |          ret_from_intr
                       |          |          |          
                       |          |          |--98.02%-- cpuidle_idle_call
                       |          |          |          cpu_idle
                       |          |          |          rest_init
                       |          |          |          start_kernel
                       |          |          |          x86_64_start_reservations
                       |          |          |          x86_64_start_kernel
                       |          |          |          
                       |          |          |--0.91%-- clockevents_notify
                       |          |          |          lapic_timer_state_broadcast
                       |          |          |          |          
                       |          |          |          |--83.64%-- acpi_idle_enter_bm
                       |          |          |          |          cpuidle_idle_call
                       |          |          |          |          cpu_idle
                       |          |          |          |          rest_init
                       |          |          |          |          start_kernel
                       |          |          |          |          x86_64_start_reservations
                       |          |          |          |          x86_64_start_kernel
                       |          |          |          |          
                       |          |          |           --16.36%-- acpi_idle_enter_simple
                       |          |          |                     cpuidle_idle_call
                       |          |          |                     cpu_idle
                       |          |          |                     rest_init
                       |          |          |                     start_kernel
                       |          |          |                     x86_64_start_reservations
                       |          |          |                     x86_64_start_kernel
                       |          |          |          
                       |          |          |--0.81%-- cpu_idle
                       |          |          |          rest_init
                       |          |          |          start_kernel
                       |          |          |          x86_64_start_reservations
                       |          |          |          x86_64_start_kernel
                       |          |           --0.26%-- [...]
                       |           --0.44%-- [...]
                       |          
                        --1.68%-- elv_completed_request
                                  __blk_put_request
                                  blk_finish_request
                                  blk_end_bidi_request
                                  blk_end_request
                                  scsi_io_completion
                                  scsi_finish_command
                                  scsi_softirq_done
                                  blk_done_softirq
                                  __do_softirq
                                  call_softirq
                                  do_softirq
                                  irq_exit
                                  do_IRQ
                                  ret_from_intr
                                  |          
                                  |--96.15%-- cpuidle_idle_call
                                  |          cpu_idle
                                  |          rest_init
                                  |          start_kernel
                                  |          x86_64_start_reservations
                                  |          x86_64_start_kernel
                                  |          
                                  |--1.92%-- cpu_idle
                                  |          rest_init
                                  |          start_kernel
                                  |          x86_64_start_reservations
                                  |          x86_64_start_kernel
                                  |          
                                  |--0.96%-- schedule
                                  |          cpu_idle
                                  |          rest_init
                                  |          start_kernel
                                  |          x86_64_start_reservations
                                  |          x86_64_start_kernel
                                  |          
                                   --0.96%-- clockevents_notify
                                             lapic_timer_state_broadcast
                                             acpi_idle_enter_bm
                                             cpuidle_idle_call
                                             cpu_idle
                                             rest_init
                                             start_kernel
                                             x86_64_start_reservations
                                             x86_64_start_kernel

    23.74%             init  [kernel.kallsyms]  [k] blk_peek_request
                       |
                       --- blk_peek_request
                           scsi_request_fn
                           __blk_run_queue
                          |          
                          |--98.77%-- blk_run_queue
                          |          scsi_run_queue
                          |          scsi_next_command
                          |          scsi_io_completion
                          |          scsi_finish_command
                          |          scsi_softirq_done
                          |          blk_done_softirq
                          |          __do_softirq
                          |          call_softirq
                          |          do_softirq
                          |          irq_exit
                          |          |          
                          |          |--99.87%-- do_IRQ
                          |          |          ret_from_intr
                          |          |          |          
                          |          |          |--98.38%-- cpuidle_idle_call
                          |          |          |          cpu_idle
                          |          |          |          start_secondary
                          |          |          |          
                          |          |          |--0.81%-- schedule
                          |          |          |          cpu_idle
                          |          |          |          start_secondary
                          |          |          |          
                          |          |          |--0.56%-- cpu_idle
                          |          |          |          start_secondary
                          |          |           --0.25%-- [...]
                          |           --0.13%-- [...]
                          |          
                           --1.23%-- elv_completed_request
                                     __blk_put_request
                                     blk_finish_request
                                     blk_end_bidi_request
                                     blk_end_request
                                     scsi_io_completion
                                     scsi_finish_command
                                     scsi_softirq_done
                                     blk_done_softirq
                                     __do_softirq
                                     call_softirq
                                     do_softirq
                                     irq_exit
                                     do_IRQ
                                     ret_from_intr
                                     cpuidle_idle_call
                                     cpu_idle
                                     start_secondary

     5.85%  chromium-browse  [kernel.kallsyms]  [k] blk_peek_request
            |
            --- blk_peek_request
                scsi_request_fn
                __blk_run_queue
                blk_run_queue
                scsi_run_queue
                scsi_next_command
                scsi_io_completion
                scsi_finish_command
                scsi_softirq_done
                blk_done_softirq
                __do_softirq
                call_softirq
                do_softirq
                irq_exit
                do_IRQ
                ret_from_intr
               |          
               |--50.00%-- check_match.8653
               |          
                --50.00%-- unlink_anon_vmas
                          free_pgtables
                          exit_mmap
                          mmput
                          exit_mm
                          do_exit
                          do_group_exit
                          sys_exit_group
                          system_call
...

  reply	other threads:[~2010-03-28  1:29 UTC|newest]

Thread overview: 32+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2010-03-16 15:31 Poor interactive performance with I/O loads with fsync()ing Ben Gamari
2010-03-17  1:24 ` tytso
2010-03-17  3:18   ` Ben Gamari
2010-03-17  3:30     ` tytso
2010-03-17  4:31       ` Ben Gamari
2010-03-26  3:16         ` Ben Gamari
2010-03-17  4:53 ` Nick Piggin
2010-03-17  9:37   ` Ingo Molnar
2010-03-26  3:31     ` Ben Gamari
2010-04-09 15:21     ` Ben Gamari
2010-03-26  3:28   ` Ben Gamari
2010-03-23 19:51 ` Jesper Krogh
2010-03-26  3:13 ` Ben Gamari
2010-03-28  1:20 ` Ben Gamari
2010-03-28  1:29   ` Ben Gamari [this message]
2010-03-28  3:42   ` Arjan van de Ven
2010-03-28 14:06     ` Ben Gamari
2010-03-28 22:08       ` Andi Kleen
2010-04-09 14:56         ` Ben Gamari
2010-04-11 15:03           ` Avi Kivity
2010-04-11 16:35             ` Ben Gamari
2010-04-11 17:20               ` Andi Kleen
2010-04-11 18:16             ` Thomas Gleixner
2010-04-11 18:42               ` Andi Kleen
2010-04-11 21:54                 ` Thomas Gleixner
2010-04-11 23:43                   ` Hans-Peter Jansen
2010-04-12  0:22               ` Dave Chinner
2010-04-14 18:40                 ` Ric Wheeler
  -- strict thread matches above, loose matches on Subject: below --
2010-03-23 11:28 Pawel S
2010-03-23 13:27 ` Jens Axboe
2010-03-26  3:35   ` Ben Gamari
2010-03-30 10:46   ` Pawel S

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=4baeb0ea.9653f10a.4c8d.5d92@mx.google.com \
    --to=bgamari.foss@gmail.com \
    --cc=jens.axboe@oracle.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=madduck@madduck.net \
    --cc=mingo@elte.hu \
    --cc=npiggin@suse.de \
    --cc=olly@survex.com \
    --cc=ruald.a@gmail.com \
    --cc=tytso@mit.edu \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.