Skip to contentSkip to conversation

Poor interactive performance with I/O loads with fsync()ing

DISCUSSION Ben Gamari 12 participants 28 messages Mar 16, 2010 – Apr 14, 2010 Btrfs file system

lore
Share & tools
lore

Ben Gamari

author
#0 lore raw

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

During these periods, even small chunks of I/O can become minute-long ordeals. It is common for latencytop to show 30 second long latencies for page faults and writing pages. Interactive performance is absolutely abysmal, with other unrelated processes feeling horrible latencies, causing media players, editors, and even terminals to grind to a halt.

Despite the system being clearly I/O bound, iostat shows pitiful disk throughput (700kByte/second read, 300 kByte/second write). Certainly this poor performance can, at least to some degree, be attributable to the fact that Xapian uses fdatasync() to ensure data consistency. That being said, it seems like Xapian's page usage causes horrible thrashing, hence the performance hit on unrelated processes. Moreover, the hit on unrelated processes is so bad that I would almost suspect that swap I/O is being serialized by fsync() as well, despite being on a separate swap partition beyond the control of the filesystem.

Xapian, however, is far from the first time I have seen this sort of performance cliff. Rsync, which also uses fsync(), can also trigger this sort of thrashing during system backups, as can rdiff. slocate's updatedb absolutely kills interactive performance as well.

Issues similar to this have been widely reported[1-5] in the past, and despite many attempts[5-8] within both I/O and memory managements subsystems to fix it, the problem certainly remains. I have tried reducing swappiness from 60 to 40, with some small improvement and it has been reported[20] that these sorts of symptoms can be negated through use of memory control groups to prevent interactive process pages from being evicted.

I would really like to see this issue finally fixed. I have tried several[2][3] times to organize the known data about this bug, although in all cases discussion has stopped with claims of insufficient data (which is fair, admittedly, it's a very difficult issue to tackle). However, I do think that _something_ has to be done to alleviate the thrashing and poor interactive performance that these work-loads cause.

Thanks,

- Ben

[1] http://bugzilla.kernel.org/show_bug.cgi?id=5900
[2] http://bugzilla.kernel.org/show_bug.cgi?id=7372
[3] http://bugzilla.kernel.org/show_bug.cgi?id=12309
[4] http://lkml.org/lkml/2009/4/28/24
[5] http://lkml.org/lkml/2009/3/26/72
[6] http://notmuchmail.org/pipermail/notmuch/2010/001868.html

[10] http://lkml.org/lkml/2009/5/16/225
[11] http://lkml.org/lkml/2007/7/21/219
[12] http://lwn.net/Articles/328363/
[13] http://lkml.org/lkml/2009/4/6/114

[20] http://lkml.org/lkml/2009/4/28/68

#1 lore raw
Quoted 9 lines · Ben Gamari

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

What kernel version are you using; what distribution and what version of that distro are you running; what file system are you using and what if any mount options are you using? And what kind of hard drives do you have?

I'm going to assume you're running into the standard ext3 "data=ordered" entagled writes problem. There are solutions, such as switching to using ext4, mounting with data=writeback mode, but they have various shortcomings.

A number of improvements have been made in ext3 and ext4 since some of the discussions you quoted, but since you didn't tell us what distribution version and/or what kernel version you are using, we can't tell you are using those newer improvements yet.

- Ted

author
#2 lore raw

Sorry about the lack of any useful information in my initial email. I clearly didn't read it before sending.

Quoted 4 lines · On Tue, 16 Mar 2010 21:24:39 -0400, [email protected] wrote:

What kernel version are you using; what distribution and what version of that distro are you running; what file system are you using and what if any mount options are you using? And what kind of hard drives do you have?

While this problem has been around for some time, my current configuration is the following:

Kernel 2.6.32 (although also reproducible with kernels at least as early as 2.6.28)
Filesystem: Now Btrfs (was ext4 less than a week ago), default mount options Hard drive: Seagate Momentus 7200.4 (ST9500420AS)
Distribution: Ubuntu 9.10 (Karmic)

Quoted 6 lines

I'm going to assume you're running into the standard ext3 "data=ordered" entagled writes problem. There are solutions, such as switching to using ext4, mounting with data=writeback mode, but they have various shortcomings.

Unfortunately several people have continued to encounter unacceptable latency, even with ext4 and data=writeback.

Quoted 5 lines

A number of improvements have been made in ext3 and ext4 since some of the discussions you quoted, but since you didn't tell us what distribution version and/or what kernel version you are using, we can't tell you are using those newer improvements yet.

Sorry about that. I should know better by now.

- Ben

#3 lore raw
Quoted 9 lines · Ben Gamari

Sorry about the lack of any useful information in my initial email. I clearly didn't read it before sending.

Quoted 4 lines · On Tue, 16 Mar 2010 21:24:39 -0400, [email protected] wrote:

What kernel version are you using; what distribution and what version of that distro are you running; what file system are you using and what if any mount options are you using? And what kind of hard drives do you have?

Quoted 7 lines

While this problem has been around for some time, my current configuration is the following:

Kernel 2.6.32 (although also reproducible with kernels at least as early as 2.6.28)
Filesystem: Now Btrfs (was ext4 less than a week ago), default mount options Hard drive: Seagate Momentus 7200.4 (ST9500420AS)
Distribution: Ubuntu 9.10 (Karmic)

.... so did switching to Btrfs solve your latency issues, or are you still having problems?

- Ted

author
#4 lore raw
Quoted 2 lines · On Tue, 16 Mar 2010 23:30:10 -0400, [email protected] wrote:

.... so did switching to Btrfs solve your latency issues, or are you still having problems?

Still having troubles although I'm now running 2.6.34-rc1 and things seem mildly better. I'll try doing a backup tonight and report back.

- Ben

author
#5 lore raw
Quoted 7 lines · Ben Gamari
Quoted 2 lines · On Tue, 16 Mar 2010 23:30:10 -0400, [email protected] wrote:

.... so did switching to Btrfs solve your latency issues, or are you still having problems?

Still having troubles although I'm now running 2.6.34-rc1 and things seem mildly better. I'll try doing a backup tonight and report back.

I stand by my assertion that 2.6.34 does seem better in some regards. While there certainly are still latency issues, it's now less often that heavy I/O spills over into over processes' interactive performance. That being said, earlier this evening Tracker and notmuch were both indexing and I saw several events of tens of seconds of latency.

- Ben

#6 lore raw
In reply to Ben Gamari

Hi,

Quoted 16 lines · Ben Gamari

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

During these periods, even small chunks of I/O can become minute-long ordeals. It is common for latencytop to show 30 second long latencies for page faults and writing pages. Interactive performance is absolutely abysmal, with other unrelated processes feeling horrible latencies, causing media players, editors, and even terminals to grind to a halt.

Quoted 6 lines

Despite the system being clearly I/O bound, iostat shows pitiful disk throughput (700kByte/second read, 300 kByte/second write). Certainly this poor performance can, at least to some degree, be attributable to the fact that Xapian uses fdatasync() to ensure data consistency. That being said, it seems like Xapian's page usage causes horrible thrashing, hence the performance hit on unrelated processes.

Where are the unrelated processes waiting? Can you get a sample of several backtraces? (/proc/<pid>/stack should do it)

Quoted 4 lines

Moreover, the hit on unrelated processes is so bad
that I would almost suspect that swap I/O is being serialized by fsync() as well, despite being on a separate swap partition beyond the control of the filesystem.

It shouldn't be, until it reaches the bio layer. If it is on the same block device, it will still fight for access. It could also be blocking on dirty data thresholds, or page reclaim though -- writeback and reclaim could easily be getting slowed down by the fsync activity.

Swapping tends to cause fairly nasty disk access patterns, combined with fsync it could be pretty unavoidable.

Quoted 6 lines

Xapian, however, is far from the first time I have seen this sort of performance cliff. Rsync, which also uses fsync(), can also trigger this sort of thrashing during system backups, as can rdiff. slocate's updatedb absolutely kills interactive performance as well.

Quoted 6 lines

Issues similar to this have been widely reported[1-5] in the past, and despite many attempts[5-8] within both I/O and memory managements subsystems to fix it, the problem certainly remains. I have tried reducing swappiness from 60 to 40, with some small improvement and it has been reported[20] that these sorts of symptoms can be negated through use of memory control groups to prevent interactive process pages from being evicted.

So the workload is causing quite a lot of swapping as well? How much pagecache do you have? It could be that you have too much pagecache and it is pushing out anonymous memory too easily, or you might have too little pagecache causing suboptimal writeout patterns (possibly writeout from page reclaim rather than asynchronous dirty page cleaner threads, which can really hurt).

Thanks,
Nick

#7 lore raw
Quoted 26 lines · Nick Piggin

Hi,

Quoted 16 lines · Ben Gamari

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

During these periods, even small chunks of I/O can become minute-long ordeals. It is common for latencytop to show 30 second long latencies for page faults and writing pages. Interactive performance is absolutely abysmal, with other unrelated processes feeling horrible latencies, causing media players, editors, and even terminals to grind to a halt.

Quoted 6 lines

Despite the system being clearly I/O bound, iostat shows pitiful disk throughput (700kByte/second read, 300 kByte/second write). Certainly this poor performance can, at least to some degree, be attributable to the fact that Xapian uses fdatasync() to ensure data consistency. That being said, it seems like Xapian's page usage causes horrible thrashing, hence the performance hit on unrelated processes.

Quoted 2 lines

Where are the unrelated processes waiting? Can you get a sample of several backtraces? (/proc/<pid>/stack should do it)

A call-graph profile will show the precise reason for IO latencies, and their relatively likelihood.

It's really simple to do it with a recent kernel. Firstly, enable CONFIG_BLK_DEV_IO_TRACE=y, CONFIG_EVENT_PROFILE=y:

Kernel performance events and counters (PERF_EVENTS) [Y/?] y
Tracepoint profiling sources (EVENT_PROFILE) [Y/n/?] y Support for tracing block IO actions (BLK_DEV_IO_TRACE) [N/y/?] y

(boot into this kernel)

Then build perf via:

cd tools/perf/
make -j install

and then capture 10 seconds of the DB workload:

perf record -f -g -a -e block:block_rq_issue -c 1 sleep 10

[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.251 MB perf.data (~10977 samples) ]

and look at the call-graph output:

perf report

# Samples: 5
#
# Overhead Command Shared Object Symbol

# ........  ...............  .................  ......
#
    80.00%        kjournald  [kernel.kallsyms]  [k] perf_trace_block_rq_issue
                  |
                  --- perf_trace_block_rq_issue
                      scsi_request_fn
                     |          
                     |--50.00%-- __blk_run_queue
                     |          cfq_insert_request
                     |          elv_insert
                     |          __elv_add_request
                     |          __make_request
                     |          generic_make_request
                     |          submit_bio
                     |          submit_bh
                     |          sync_dirty_buffer
                     |          journal_commit_transaction
                     |          kjournald
                     |          kthread
                     |          kernel_thread_helper
                     |          
                      --50.00%-- __generic_unplug_device
                                generic_unplug_device
                                blk_unplug
                                blk_backing_dev_unplug
                                sync_buffer
                                __wait_on_bit
                                out_of_line_wait_on_bit
                                __wait_on_buffer
                                wait_on_buffer
                                journal_commit_transaction
                                kjournald
                                kthread
                                kernel_thread_helper
    20.00%               as  [kernel.kallsyms]  [k] perf_trace_block_rq_issue
                         |
                         --- perf_trace_block_rq_issue
                             scsi_request_fn
                             __generic_unplug_device
                             generic_unplug_device
                             blk_unplug
                             blk_backing_dev_unplug
                             page_cache_async_readahead
                             generic_file_aio_read
                             do_sync_read
                             vfs_read
                             sys_read
                             system_call_fastpath
                             0x39f8ad4930

This (very simple) example had 80% of the IO in kjournald and 20% of it in 'as'. The precise call-paths of IO issues are visible.

For general scheduler context-switch events you can use:

perf record -f -g -a -e context-switches -c 1 sleep 10

see 'perf list' for all events.

Thanks,

Ingo

author
#8 lore raw
Quoted 4 lines · Ingo Molnar

A call-graph profile will show the precise reason for IO latencies, and their relatively likelihood.

Once I get home I'll try to reproduce the issue and get a call graph. Thanks!

- Ben

author
#9 lore raw
In reply to Ingo Molnar
Quoted 28 lines · Ingo Molnar
Quoted 26 lines · Nick Piggin

Hi,

Quoted 22 lines · Ben Gamari

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

During these periods, even small chunks of I/O can become minute-long ordeals. It is common for latencytop to show 30 second long latencies for page faults and writing pages. Interactive performance is absolutely abysmal, with other unrelated processes feeling horrible latencies, causing media players, editors, and even terminals to grind to a halt.

Despite the system being clearly I/O bound, iostat shows pitiful disk throughput (700kByte/second read, 300 kByte/second write). Certainly this poor performance can, at least to some degree, be attributable to the fact that Xapian uses fdatasync() to ensure data consistency. That being said, it seems like Xapian's page usage causes horrible thrashing, hence the performance hit on unrelated processes.

Quoted 6 lines
Quoted 2 lines

Where are the unrelated processes waiting? Can you get a sample of several backtraces? (/proc/<pid>/stack should do it)

A call-graph profile will show the precise reason for IO latencies, and their relatively likelihood.

Are these backtraces at all useful? I've received no feedback thusfar, so I can only that either,
a) there is insufficient data to draw any conclusions and there is no interest in pursuing this further, or
b) nobody has looked at the backtraces

As I've said in the past, I am very interested in seeing this problem looked at and would love to contribute whatever I can to that effort. However, without knowing what information is necessary, I can be of only very limited use in my own debugging efforts. Thanks,

- Ben

author
#10 lore raw
In reply to Nick Piggin
Quoted 3 lines · Nick Piggin

Where are the unrelated processes waiting? Can you get a sample of several backtraces? (/proc/<pid>/stack should do it)

I wish. One of the incredibly frustrating characteristics of this issue is the difficulty in measuring it. By the time processes begin blocking, it's already far too late to open a terminal and cat to a file. By the time the terminal has opened, tens of seconds have passed and things have started to return to normal.

Quoted 11 lines
Quoted 5 lines

Moreover, the hit on unrelated processes is so bad
that I would almost suspect that swap I/O is being serialized by fsync() as well, despite being on a separate swap partition beyond the control of the filesystem.

It shouldn't be, until it reaches the bio layer. If it is on the same block device, it will still fight for access. It could also be blocking on dirty data thresholds, or page reclaim though -- writeback and reclaim could easily be getting slowed down by the fsync activity.

Hmm, this sounds interesting. Is there a way to monitor writeback throughput.

Quoted 3 lines

Swapping tends to cause fairly nasty disk access patterns, combined with fsync it could be pretty unavoidable.

This is definitely a possibility. However, it seems to me like swapping should be at least mildly favored over other I/O by the I/O scheduler. That being said, I can certainly see how it would be difficult to implement such a heuristic in a fair way so as not to block out standard filesystem access during a thrashing spree.

Quoted 13 lines
Quoted 6 lines

Xapian, however, is far from the first time I have seen this sort of performance cliff. Rsync, which also uses fsync(), can also trigger this sort of thrashing during system backups, as can rdiff. slocate's updatedb absolutely kills interactive performance as well.

Quoted 6 lines

Issues similar to this have been widely reported[1-5] in the past, and despite many attempts[5-8] within both I/O and memory managements subsystems to fix it, the problem certainly remains. I have tried reducing swappiness from 60 to 40, with some small improvement and it has been reported[20] that these sorts of symptoms can be negated through use of memory control groups to prevent interactive process pages from being evicted.

Quoted 7 lines

So the workload is causing quite a lot of swapping as well? How much pagecache do you have? It could be that you have too much pagecache and it is pushing out anonymous memory too easily, or you might have too little pagecache causing suboptimal writeout patterns (possibly writeout from page reclaim rather than asynchronous dirty page cleaner threads, which can really hurt).

As far as I can tell, the workload should fit in memory without a problem. This machine has 4 gigabytes of memory, of which currently 2.8GB is page cache. Seems high perhaps? I've included meminfo below. I can completely see how overly-aggressive page-cache would result in this sort of behavior.

- Ben

MemTotal:        4048068 kB
MemFree:           47232 kB
Buffers:              48 kB
Cached:          2774648 kB
SwapCached:         1148 kB
Active:          2353572 kB
Inactive:        1355980 kB
Active(anon):    1343176 kB
Inactive(anon):   342644 kB
Active(file):    1010396 kB
Inactive(file):  1013336 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:       4883756 kB
SwapFree:        4882532 kB
Dirty:             24736 kB
Writeback:             0 kB
AnonPages:        933820 kB
Mapped:            88840 kB
Shmem:            750948 kB
Slab:             150752 kB
SReclaimable:     121404 kB
SUnreclaim:        29348 kB
KernelStack:        2672 kB
PageTables:        31312 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     6907788 kB
Committed_AS:    2773672 kB
VmallocTotal:   34359738367 kB
VmallocUsed:      364080 kB
VmallocChunk:   34359299100 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:        8552 kB
DirectMap2M:     4175872 kB
#11 lore raw
In reply to Ben Gamari
Quoted 9 lines · Ben Gamari

Hey all,

Recently I started using the Xapian-based notmuch mail client for everyday use. One of the things I was quite surprised by after the switch was the incredible hit in interactive performance that is observed during database updates. Things are particularly bad during runs of 'notmuch new,' which scans the file system looking for new messages and adds them to the database. Specifically, the worst of the performance hit appears to occur when the database is being updated.

I would suggest that you include a 2.6.31 kernel in your testing. I have seen something that seems like "huge" stalls in 2.6.32 but I havent been able to "dig into it" to find more.

In 2.6.32 I have seen IO-wait numbers around 80% on a 16 core machine with 128GB of memory and load-numbers over 120 under workloads that didn't make 2.6.31 sweat at all.

Filesystems are a mixture of ext3 and ext4 (so it could be the barriers)?

Signature · 1 line
Jesper
author
#12 lore raw
In reply to Ben Gamari
Quoted 1 line · Ben Gamari

Hey all,

I apologize for my extreme tardiness in replying to your responses. I was hoping to have more time during Spring break in dealing with this issue than I did (as always). Nevertheless, I'll hopefully be able to keep up with things at this point. Specific replies will follow.

- Ben

author
#13 lore raw
In reply to Ben Gamari

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.

Anyone have any ideas on how to proceed? Is more profile data necessary? Are the existing profiles at all useful? Thanks,

- Ben

author
#14 lore raw
Quoted 7 lines · Ben Gamari

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 <[email protected]>
Subject: Re: Poor interactive performance with I/O loads with fsync()ing
To: Ingo Molnar <[email protected]>, Nick Piggin <[email protected]>
Cc: [email protected], [email protected], Olly Betts
<[email protected]>, martin f krafft <[email protected]>
Bcc: [email protected]
In-Reply-To: <[email protected]>
References: <[email protected]>

	<20100317045350.GA2869@laptop> <[email protected]>
Quoted 2 lines · Ingo Molnar

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

...

#15 lore raw
In reply to Ben Gamari
Quoted 10 lines · On Sat, 27 Mar 2010 18:20:37 -0700 (PDT) Ben Gamari <[email protected]>…

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.

Anyone have any ideas on how to proceed? Is more profile data necessary? Are the existing profiles at all useful? Thanks,

profiles tend to be about cpu usage... and are rather poor to deal with anything IO related.

latencytop might get closer in giving useful information....

(btw some general suggestion.. make sure you're using noatime or relatime as mount option)

Signature · 3 lines
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org
author
#16 lore raw
Quoted 10 lines · Arjan van de Ven
Quoted 7 lines · On Sat, 27 Mar 2010 18:20:37 -0700 (PDT) Ben Gamari <[email protected]>…

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.

I suppose this statement was a tad misleading. The provided profiles were taken with,

perf record -f -g -a -e block:block_rq_issue -c 1

Which I believe measures block requests issued, not CPU usage (correct me if I'm wrong).

Quoted 3 lines

profiles tend to be about cpu usage... and are rather poor to deal with anything IO related.

See above.

Quoted 2 lines

latencytop might get closer in giving useful information....

Latencytop generally shows a large amount of time handling page faults.

Quoted 2 lines

(btw some general suggestion.. make sure you're using noatime or relatime as mount option)

Thanks for the suggestion. I had actually forgotten relatime in my fstab, so we'll see if there's any improvement now. That being said, I/O loads over small numbers of files (e.g. xapian) are just as bad as loads over large numbers of files. To me that weakly suggests perhaps atime updates aren't the issue (I could be horribly wrong though).

- Ben

#17 lore raw

Ben Gamari <[email protected]> writes:

You don't say which file system you use, but ext3 and the file systems with similar journal design (like reiserfs) all have known fsync starvation issues. The problem is that any fsync has to wait for all transactions to commit, and this might take a long time depending on how busy the disk is.

ext4/XFS/JFS/btrfs should be better in this regard

-Andi

Signature · 1 line
[email protected] -- Speaking for myself only.
author
#18 lore raw
Quoted 3 lines · Andi Kleen

Ben Gamari <[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

I am using btrfs, so yes, I was expecting things to be better. Unfortunately, the improvement seems to be non-existent under high IO/fsync load.

- Ben

#19 lore raw
Quoted 10 lines · Ben Gamari
Quoted 4 lines · Andi Kleen

Ben Gamari<[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

I am using btrfs, so yes, I was expecting things to be better. Unfortunately, the improvement seems to be non-existent under high IO/fsync load.

btrfs is known to perform poorly under fsync.

Signature · 1 line
error compiling committee.c: too many arguments to function
author
#20 lore raw
Quoted 7 lines · Avi Kivity
Quoted 6 lines · Ben Gamari
Quoted 4 lines · Andi Kleen

Ben Gamari<[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

Quoted 6 lines
Quoted 3 lines

I am using btrfs, so yes, I was expecting things to be better. Unfortunately, the improvement seems to be non-existent under high IO/fsync load.

btrfs is known to perform poorly under fsync.

Has the reason for this been identified? Judging from the nature of metadata loads, it would seem that it should be substantially easier to implement fsync() efficiently.

- Ben

#21 lore raw
Quoted 3 lines

Has the reason for this been identified? Judging from the nature of metadata loads, it would seem that it should be substantially easier to implement fsync() efficiently.

By design a copy on write tree fs would need to flush a whole tree hierarchy on a sync. btrfs avoids this by using a special log for fsync, but that causes more overhead if you have that log on the same disk. So IO subsystem will do more work.

It's a bit like JBD data journaling.

However it should not have the stalls inherent in ext3's journaling.

-Andi

Signature · 1 line
[email protected] -- Speaking for myself only.
#22 lore raw
In reply to Avi Kivity
Quoted 7 lines · Avi Kivity
Quoted 6 lines · Ben Gamari
Quoted 4 lines · Andi Kleen

Ben Gamari<[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

Quoted 7 lines
Quoted 5 lines

I am using btrfs, so yes, I was expecting things to be better. Unfortunately,
the improvement seems to be non-existent under high IO/fsync load.

btrfs is known to perform poorly under fsync.

XFS does not do much better. Just moved my VM images back to ext for that reason.

Thanks,

tglx

#23 lore raw
Quoted 2 lines

XFS does not do much better. Just moved my VM images back to ext for that reason.

Did you move from XFS to ext3? ext3 defaults to barriers off, XFS on, which can make a big difference depending on the disk. You can disable them on XFS too of course, with the known drawbacks.

XFS also typically needs some tuning to get reasonable log sizes.

My point was merely (before people chime in with counter examples) that XFS/btrfs/jfs don't suffer from the "need to sync all transactions for every fsync" issue. There can (and will be) still other issues.

-Andi

Signature · 1 line
[email protected] -- Speaking for myself only.
#24 lore raw
Quoted 7 lines · Andi Kleen
Quoted 2 lines

XFS does not do much better. Just moved my VM images back to ext for that reason.

Did you move from XFS to ext3? ext3 defaults to barriers off, XFS on, which can make a big difference depending on the disk. You can disable them on XFS too of course, with the known drawbacks.

Quoted 5 lines

XFS also typically needs some tuning to get reasonable log sizes.

My point was merely (before people chime in with counter examples) that XFS/btrfs/jfs don't suffer from the "need to sync all transactions for every fsync" issue. There can (and will be) still other issues.

Yes, I moved them back from XFS to ext3 simply because moving them from ext3 to XFS turned out to be a completely unusable disaster.

I know that I can tweak knobs on XFS (or any other file system), but I would not have expected that it sucks that much for KVM with the default settings which are perfectly fine for the other use cases which made us move to XFS.

Thanks,

tglx

#25 lore raw
Quoted 14 lines · On Sunday 11 April 2010, 23:54:34 Thomas Gleixner wrote:
Quoted 7 lines · Andi Kleen
Quoted 2 lines

XFS does not do much better. Just moved my VM images back to ext for that reason.

Did you move from XFS to ext3? ext3 defaults to barriers off, XFS on, which can make a big difference depending on the disk. You can disable them on XFS too of course, with the known drawbacks.

Quoted 5 lines

XFS also typically needs some tuning to get reasonable log sizes.

My point was merely (before people chime in with counter examples) that XFS/btrfs/jfs don't suffer from the "need to sync all transactions for every fsync" issue. There can (and will be) still other issues.

Quoted 7 lines

Yes, I moved them back from XFS to ext3 simply because moving them from ext3 to XFS turned out to be a completely unusable disaster.

I know that I can tweak knobs on XFS (or any other file system), but I would not have expected that it sucks that much for KVM with the default settings which are perfectly fine for the other use cases which made us move to XFS.

Thomas, what Andi was merely turning out, is that xfs has a really concerning different default: barriers, that hurts with fsync().

In order to make a fair comparison of the two, you may want to mount xfs with nobarrier or ext3 with barrier option set, and _then_ check which one is sucking less.

I guess, that outcome will be interesting for quite a bunch of people in the audience (including me¹).

Pete

¹) while in transition of getting rid of even suckier technology junk like
VMware-Server - but digging out a current², but _stable_ kernel release seems harder then ever nowadays.
²) with operational VT-d support for kvm

#26 lore raw
In reply to Thomas Gleixner
Quoted 6 lines · Thomas Gleixner
Quoted 5 lines · Avi Kivity
Quoted 4 lines · Ben Gamari
Quoted 3 lines · Andi Kleen

Ben Gamari<[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

Quoted 8 lines
Quoted 5 lines
Quoted 3 lines

I am using btrfs, so yes, I was expecting things to be better. Unfortunately,
the improvement seems to be non-existent under high IO/fsync load.

btrfs is known to perform poorly under fsync.

XFS does not do much better. Just moved my VM images back to ext for that reason.

Numbers? Workload description? Mount options? I hate it when all I hear is "XFS sucked, so I went back to extN" reports without any more details - it's hard to improve anything without any details of the problems.

Also worth remembering is that XFS defaults to slow-but-safe options, but ext3 defaults to fast-and-I-don't-give-a-damn-about- data-safety, so there's a world of difference between the filesystem defaults....

And FWIW, I run all my VMs on XFS using default mkfs and mount options, and I can't say that I've noticed any performance problems at all despite hammering the IO subsystems all the time. The only thing I've ever done is occasionally run xfs_fsr across permanent qcow2 VM images to defrag them as the grow slowly over time...

Cheers,

Dave.

Signature · 2 lines
Dave Chinner
[email protected]
#27 lore raw
Quoted 37 lines · Dave Chinner
Quoted 10 lines · Thomas Gleixner
Quoted 8 lines · Avi Kivity
Quoted 6 lines · Ben Gamari
Quoted 4 lines · Andi Kleen

Ben Gamari<[email protected]> writes:
ext4/XFS/JFS/btrfs should be better in this regard

Quoted 9 lines
Quoted 6 lines
Quoted 4 lines

I am using btrfs, so yes, I was expecting things to be better. Unfortunately,
the improvement seems to be non-existent under high IO/fsync load.

btrfs is known to perform poorly under fsync.

XFS does not do much better. Just moved my VM images back to ext for that reason.

Numbers? Workload description? Mount options? I hate it when all I hear is "XFS sucked, so I went back to extN" reports without any more details - it's hard to improve anything without any details of the problems.

Also worth remembering is that XFS defaults to slow-but-safe options, but ext3 defaults to fast-and-I-don't-give-a-damn-about- data-safety, so there's a world of difference between the filesystem defaults....

And FWIW, I run all my VMs on XFS using default mkfs and mount options, and I can't say that I've noticed any performance problems at all despite hammering the IO subsystems all the time. The only thing I've ever done is occasionally run xfs_fsr across permanent qcow2 VM images to defrag them as the grow slowly over time...

Quoted 4 lines

Cheers,

Dave.

And if you are asking for details, the type of storage you use is also quite interesting.

Thanks!

Ric