public inbox for linux-kernel@vger.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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox