All of lore.kernel.org
 help / color / mirror / Atom feed
* [4.2, Regression] Queued spinlocks cause major XFS performance regression
@ 2015-09-04  5:48 Dave Chinner
  2015-09-04  6:39 ` Linus Torvalds
  2015-09-10  2:01 ` Waiman Long
  0 siblings, 2 replies; 32+ messages in thread
From: Dave Chinner @ 2015-09-04  5:48 UTC (permalink / raw)
  To: linux-kernel; +Cc: peterz, Waiman.Long, torvalds

Hi Waiman,

For the first time in months I just turned of spinlock debugging on
my performance test machine and I just got an unpleasant surprise on
my standard inode allocation and reclaim test.  I've described this
test to you before, because it's found regressions in your previous
lock scaling changes:

http://permalink.gmane.org/gmane.linux.kernel/1768786

This time it is the fsmark run that I use to populate the filesystem
that is demonstrating a locking regression. I'll asked you before
if you could add this test to your lock scaling regression test
suite; please do it this time.

Now, the regression.  With spinlock debugging turned on, the
performance of my usual XFS inode allocation benchmark using fsmark
reports performance like this:

FSUse%        Count         Size    Files/sec     App Overhead
     0      1600000            0     312594.0          9944159
     0      3200000            0     295668.6         10399679
     0      4800000            0     279026.1         11397617
.....

This has been pretty stable for several releases - it varies +/- a
few percent, but it's pretty much been like this since about 3.2
when CONFIG_XFS_DEBUG=n, with or without basic spinlock debugging.

When I turned spinlock debugging off on 4.2 to get some perf numbers
a request from Linus, I got this:

FSUse%        Count         Size    Files/sec     App Overhead
     0      1600000            0     114143.9          9597599
     0      3200000            0      95486.9          9460413
     0      4800000            0      93918.2          9784699
....

All 16 CPUs were pegged at 100% cpu usage. I took a quick look at
perf:

  67.32%  [kernel]       [k] queued_spin_lock_slowpath
   5.17%  [kernel]       [k] xfs_log_commit_cil
   2.47%  [kernel]       [k] _xfs_buf_find
   1.37%  [kernel]       [k] _raw_spin_lock
   ....

And then a quick call graph sample to find the lock:

   37.19%    37.19%  [kernel]         [k] queued_spin_lock_slowpath
   - queued_spin_lock_slowpath
      - 99.98% _raw_spin_lock
         - 89.16% xfs_log_commit_cil
            - __xfs_trans_commit
               - 98.48% xfs_trans_commit
                    xfs_create
                    xfs_generic_create
                    xfs_vn_mknod
                    xfs_vn_create
                    vfs_create
                    path_openat
                    do_filp_open
                    do_sys_open
                    sys_open
                    entry_SYSCALL_64_fastpath
                  + __GI___libc_open
               + 1.52% __xfs_trans_roll

This shows that we have catastrophic spinlock contention in the
transaction commit path. The cil->xc_cil_lock spin lock as it's the
only spinlock in that path. And while it's the hot lock in the
commit path, turning spinlock debugging back on (and no other
changes) shows that it shouldn't be contended:

   8.92%  [kernel]  [k] _xfs_buf_find
   5.51%  [kernel]  [k] xfs_dir2_node_addname
   3.49%  [kernel]  [k] xfs_dir3_free_hdr_from_disk
   3.45%  [kernel]  [k] do_raw_spin_lock
   3.06%  [kernel]  [k] kmem_cache_alloc
   2.99%  [kernel]  [k] __memcpy
   2.97%  [kernel]  [k] xfs_log_commit_cil
   .....

And the call graph:

    4.52%     0.24%  [kernel]            [k] _raw_spin_lock
   - _raw_spin_lock
      + 43.63% xfs_log_commit_cil
      + 9.76% inode_sb_list_add
      + 8.57% list_lru_add
      + 6.37% _xfs_buf_find
      + 6.08% d_alloc
      + 4.18% dput
      + 4.08% __d_instantiate
...

IOWs, about 2% of the cpu usage is lock traffic through
cil->xc_cil_lock, and that's 3x the locking rate where the queued
spinlock becomes catastrophically contention bound.

To confirm that this is indeed caused by the queued spinlocks, I
removed the the spinlock debugging and did this to arch/x86/Kconfig:

-       select ARCH_USE_QUEUED_SPINLOCK

And the results are:

FSUse%        Count         Size    Files/sec     App Overhead
     0      1600000            0     329310.4          9727415
     0      3200000            0     305421.4         10421358
     0      4800000            0     294593.3         11007112
     0      6400000            0     283863.7         12557190
....

So the problem is definitely the queued spinlock...

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

^ permalink raw reply	[flat|nested] 32+ messages in thread

end of thread, other threads:[~2015-09-29  2:57 UTC | newest]

Thread overview: 32+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-09-04  5:48 [4.2, Regression] Queued spinlocks cause major XFS performance regression Dave Chinner
2015-09-04  6:39 ` Linus Torvalds
2015-09-04  7:11   ` Dave Chinner
2015-09-04  7:31     ` Juergen Gross
2015-09-04  7:55     ` Peter Zijlstra
2015-09-04  8:29     ` Dave Chinner
2015-09-04 15:05       ` Linus Torvalds
2015-09-04 15:14         ` Peter Zijlstra
2015-09-04 15:21           ` Linus Torvalds
2015-09-04 15:30             ` Peter Zijlstra
2015-09-04 15:54               ` Peter Zijlstra
2015-09-10  2:06                 ` Waiman Long
2015-09-04 15:58               ` Linus Torvalds
2015-09-05 17:45                 ` Peter Zijlstra
2015-09-04 15:25           ` Peter Zijlstra
2015-09-06 23:32             ` Dave Chinner
2015-09-07  0:05             ` Davidlohr Bueso
2015-09-07  6:57               ` Peter Zijlstra
2015-09-07 20:45                 ` Linus Torvalds
2015-09-08  6:37                   ` Davidlohr Bueso
2015-09-08 10:05                   ` Peter Zijlstra
2015-09-08 17:45                     ` Linus Torvalds
2015-09-13 10:55             ` [tip:locking/core] locking/qspinlock/x86: Fix performance regression under unaccelerated VMs tip-bot for Peter Zijlstra
2015-09-04  7:39   ` [4.2, Regression] Queued spinlocks cause major XFS performance regression Peter Zijlstra
2015-09-04  8:12     ` Dave Chinner
2015-09-04 11:32       ` Peter Zijlstra
2015-09-04 22:03         ` Dave Chinner
2015-09-06 23:47         ` Dave Chinner
2015-09-10  2:09           ` Waiman Long
     [not found]         ` <CAC=cRTOraeOeu3Z8C1qx6w=GMSzD_4VevrEzn0mMhrqy=7n3wQ@mail.gmail.com>
     [not found]           ` <56094F05.4090809@hpe.com>
2015-09-29  0:47             ` huang ying
2015-09-29  2:57               ` Waiman Long
2015-09-10  2:01 ` Waiman Long

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.