* sched: context tracking demolishes pipe-test
@ 2013-06-30 7:57 Mike Galbraith
2013-06-30 21:29 ` Peter Zijlstra
0 siblings, 1 reply; 8+ messages in thread
From: Mike Galbraith @ 2013-06-30 7:57 UTC (permalink / raw)
To: LKML; +Cc: Peter Zijlstra, Ingo Molnar
taskset -c 3 pipe-test 1
switch-rate
3.10.0-master 426.4 KHz
3.10.0-masterx 591.8 Khz 1.387 (591=notgood, 426=omfg)
3.10.0-master 3.10.0-masterx
7.13% [k] __schedule 9.58% [k] __schedule
! 6.02% [.] __read_nocancel 8.25% [k] system_call
! 5.82% [.] __write_nocancel 5.34% [k] _raw_spin_lock_irqsave
! 4.28% [k] system_call 4.26% [k] pipe_read
! 4.13% [k] user_exit 3.53% [k] copy_user_generic_string
3.64% [k] _raw_spin_lock_irqsave 3.52% [k] native_sched_clock
3.37% [k] pipe_read 3.43% [k] __switch_to
2.72% [k] copy_user_generic_string 3.21% [.] main
2.60% [.] main 2.96% [k] mutex_lock
2.59% [k] native_sched_clock 2.89% [k] mutex_unlock
2.47% [k] __switch_to 2.86% [k] sched_clock_local
2.10% [k] mutex_unlock 2.63% [.] __read_nocancel
2.08% [k] sched_clock_local 2.47% [k] pipe_write
2.05% [k] mutex_lock 2.37% [k] _raw_spin_unlock_irqrestore
1.91% [k] pipe_write 1.96% [.] __write_nocancel
1.89% [k] user_enter 1.62% [k] vfs_write
1.72% [k] _raw_spin_unlock_irqrestore 1.54% [k] do_sync_write
1.51% [k] rcu_eqs_enter_common.isra.47 1.52% [k] fget_light
1.41% [k] rcu_eqs_exit_common.isra.45 1.48% [k] fsnotify
1.30% [k] tracesys 1.39% [k] dequeue_task_fair
1.23% [k] fsnotify 1.39% [k] update_curr
1.23% [k] int_check_syscall_exit_worka 1.37% [k] do_sync_read
1.20% [k] fget_light 1.33% [.] __GI___libc_write
1.16% [k] vfs_write 1.29% [k] try_to_wake_up
1.05% [k] syscall_trace_enter 1.09% [k] _raw_spin_lock_irq
1.04% [k] do_sync_write 1.08% [k] pipe_iov_copy_from_user
1.03% [k] context_tracking_task_switch 1.05% [k] finish_task_switch
0.99% [k] update_curr 1.04% [k] prepare_to_wait
marge:/usr/local/src/kernel/linux-3.x.git # diff -up config.horrible config.not-as-bad
--- config.horrible 2013-06-30 08:38:47.785258079 +0200
+++ config.not-as-bad 2013-06-30 08:33:08.246761153 +0200
@@ -48,7 +48,7 @@ CONFIG_BUILDTIME_EXTABLE_SORT=y
#
CONFIG_INIT_ENV_ARG_LIMIT=32
CONFIG_CROSS_COMPILE=""
-CONFIG_LOCALVERSION="-master"
+CONFIG_LOCALVERSION="-masterx"
# CONFIG_LOCALVERSION_AUTO is not set
CONFIG_HAVE_KERNEL_GZIP=y
CONFIG_HAVE_KERNEL_BZIP2=y
@@ -126,7 +126,7 @@ CONFIG_TREE_RCU=y
CONFIG_RCU_STALL_COMMON=y
CONFIG_CONTEXT_TRACKING=y
CONFIG_RCU_USER_QS=y
-CONFIG_CONTEXT_TRACKING_FORCE=y
+# CONFIG_CONTEXT_TRACKING_FORCE is not set
CONFIG_RCU_FANOUT=64
CONFIG_RCU_FANOUT_LEAF=16
# CONFIG_RCU_FANOUT_EXACT is not set
marge:/usr/local/src/kernel/linux-3.x.git # grep NO_HZ .config
CONFIG_NO_HZ_COMMON=y
CONFIG_NO_HZ_IDLE=y
# CONFIG_NO_HZ_FULL is not set
CONFIG_NO_HZ=y
# CONFIG_RCU_FAST_NO_HZ is not set
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-06-30 7:57 sched: context tracking demolishes pipe-test Mike Galbraith
@ 2013-06-30 21:29 ` Peter Zijlstra
2013-07-01 6:07 ` Mike Galbraith
0 siblings, 1 reply; 8+ messages in thread
From: Peter Zijlstra @ 2013-06-30 21:29 UTC (permalink / raw)
To: Mike Galbraith; +Cc: LKML, Ingo Molnar
On Sun, Jun 30, 2013 at 09:57:36AM +0200, Mike Galbraith wrote:
> taskset -c 3 pipe-test 1
>
> switch-rate
> 3.10.0-master 426.4 KHz
> 3.10.0-masterx 591.8 Khz 1.387 (591=notgood, 426=omfg)
>
> 3.10.0-master 3.10.0-masterx
> 7.13% [k] __schedule 9.58% [k] __schedule
> ! 6.02% [.] __read_nocancel 8.25% [k] system_call
> ! 5.82% [.] __write_nocancel 5.34% [k] _raw_spin_lock_irqsave
> ! 4.28% [k] system_call 4.26% [k] pipe_read
> ! 4.13% [k] user_exit 3.53% [k] copy_user_generic_string
> 3.64% [k] _raw_spin_lock_irqsave 3.52% [k] native_sched_clock
> 3.37% [k] pipe_read 3.43% [k] __switch_to
> 2.72% [k] copy_user_generic_string 3.21% [.] main
> 2.60% [.] main 2.96% [k] mutex_lock
> 2.59% [k] native_sched_clock 2.89% [k] mutex_unlock
> 2.47% [k] __switch_to 2.86% [k] sched_clock_local
> 2.10% [k] mutex_unlock 2.63% [.] __read_nocancel
> 2.08% [k] sched_clock_local 2.47% [k] pipe_write
> 2.05% [k] mutex_lock 2.37% [k] _raw_spin_unlock_irqrestore
> 1.91% [k] pipe_write 1.96% [.] __write_nocancel
> 1.89% [k] user_enter 1.62% [k] vfs_write
> 1.72% [k] _raw_spin_unlock_irqrestore 1.54% [k] do_sync_write
> 1.51% [k] rcu_eqs_enter_common.isra.47 1.52% [k] fget_light
> 1.41% [k] rcu_eqs_exit_common.isra.45 1.48% [k] fsnotify
> 1.30% [k] tracesys 1.39% [k] dequeue_task_fair
> 1.23% [k] fsnotify 1.39% [k] update_curr
> 1.23% [k] int_check_syscall_exit_worka 1.37% [k] do_sync_read
> 1.20% [k] fget_light 1.33% [.] __GI___libc_write
> 1.16% [k] vfs_write 1.29% [k] try_to_wake_up
> 1.05% [k] syscall_trace_enter 1.09% [k] _raw_spin_lock_irq
> 1.04% [k] do_sync_write 1.08% [k] pipe_iov_copy_from_user
> 1.03% [k] context_tracking_task_switch 1.05% [k] finish_task_switch
> 0.99% [k] update_curr 1.04% [k] prepare_to_wait
>
Yeah, who'd have thought that putting stuff in the syscall path would've
made syscalls more expensive ;-)
But yeah, that's a _lot_ more expensive.. I'd not be surprised if more
people would find that objectionable.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-06-30 21:29 ` Peter Zijlstra
@ 2013-07-01 6:07 ` Mike Galbraith
2013-07-01 8:06 ` Peter Zijlstra
0 siblings, 1 reply; 8+ messages in thread
From: Mike Galbraith @ 2013-07-01 6:07 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: LKML, Ingo Molnar
On Sun, 2013-06-30 at 23:29 +0200, Peter Zijlstra wrote:
> Yeah, who'd have thought that putting stuff in the syscall path would've
> made syscalls more expensive ;-)
(careful, you'll injure my innocence, Santa and the Tooth Fairy exist!)
> But yeah, that's a _lot_ more expensive.. I'd not be surprised if more
> people would find that objectionable.
Distros may want some hot patching or _something_ before doing the usual
new=turn-it-on thing. Per trusty (spelled with 'c') old Q6600, the cost
is pretty darn high.
-regress is my ~light regression testing config, carried forward from
3.6.32...master across all intervening trees.
-regressx is plus CONFIG_RCU_USER_QS=y CONFIG_CONTEXT_TRACKING_FORCE=y
-regressxx is plus full dynticks
taskset -c 3 pipe-test 1
2.6.32-regress 654.5 Khz 1.000
3.10.0-regress 652.1 Khz .996 1.000
3.10.0-regressx 476.8 Khz .728 .731
3.10.0-regressxx 275.6 Khz .421 .422
tbench
2.6.32-regress 327.502 MB/sec 1.000
3.10.0-regress 319.621 MB/sec .975 1.000
3.10.0-regressx 292.894 MB/sec .894 .916
3.10.0-regressxx 243.738 MB/sec .744 .762
netperf TCP_RR
2.6.32-regress 104041.84 Trans/sec 1.000
3.10.0-regress 94961.34 Trans/sec .912 1.000
3.10.0-regressx 82383.33 Trans/sec .791 .867
3.10.0-regressxx 61527.59 Trans/sec .591 .647
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-07-01 6:07 ` Mike Galbraith
@ 2013-07-01 8:06 ` Peter Zijlstra
2013-07-01 9:12 ` Mike Galbraith
0 siblings, 1 reply; 8+ messages in thread
From: Peter Zijlstra @ 2013-07-01 8:06 UTC (permalink / raw)
To: Mike Galbraith; +Cc: LKML, Ingo Molnar
On Mon, Jul 01, 2013 at 08:07:55AM +0200, Mike Galbraith wrote:
> On Sun, 2013-06-30 at 23:29 +0200, Peter Zijlstra wrote:
>
> > Yeah, who'd have thought that putting stuff in the syscall path would've
> > made syscalls more expensive ;-)
>
> (careful, you'll injure my innocence, Santa and the Tooth Fairy exist!)
>
> > But yeah, that's a _lot_ more expensive.. I'd not be surprised if more
> > people would find that objectionable.
>
> Distros may want some hot patching or _something_ before doing the usual
> new=turn-it-on thing. Per trusty (spelled with 'c') old Q6600, the cost
> is pretty darn high.
>
> -regress is my ~light regression testing config, carried forward from
> 3.6.32...master across all intervening trees.
> -regressx is plus CONFIG_RCU_USER_QS=y CONFIG_CONTEXT_TRACKING_FORCE=y
> -regressxx is plus full dynticks
>
> taskset -c 3 pipe-test 1
>
> 2.6.32-regress 654.5 Khz 1.000
> 3.10.0-regress 652.1 Khz .996 1.000
> 3.10.0-regressx 476.8 Khz .728 .731
> 3.10.0-regressxx 275.6 Khz .421 .422
>
> tbench
>
> 2.6.32-regress 327.502 MB/sec 1.000
> 3.10.0-regress 319.621 MB/sec .975 1.000
> 3.10.0-regressx 292.894 MB/sec .894 .916
> 3.10.0-regressxx 243.738 MB/sec .744 .762
>
> netperf TCP_RR
>
> 2.6.32-regress 104041.84 Trans/sec 1.000
> 3.10.0-regress 94961.34 Trans/sec .912 1.000
> 3.10.0-regressx 82383.33 Trans/sec .791 .867
> 3.10.0-regressxx 61527.59 Trans/sec .591 .647
So aside from the context tracking stuff, there's still a regression
we might want to look at. That's still a ~10% drop against 2.6.32 for
TCP_RR and few percents for tbench.
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-07-01 8:06 ` Peter Zijlstra
@ 2013-07-01 9:12 ` Mike Galbraith
2013-07-01 9:20 ` Mike Galbraith
0 siblings, 1 reply; 8+ messages in thread
From: Mike Galbraith @ 2013-07-01 9:12 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: LKML, Ingo Molnar
On Mon, 2013-07-01 at 10:06 +0200, Peter Zijlstra wrote:
> So aside from the context tracking stuff, there's still a regression
> we might want to look at. That's still a ~10% drop against 2.6.32 for
> TCP_RR and few percents for tbench.
Yeah, known, and some of it's ours.
-Mike
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-07-01 9:12 ` Mike Galbraith
@ 2013-07-01 9:20 ` Mike Galbraith
2013-07-02 4:03 ` Mike Galbraith
0 siblings, 1 reply; 8+ messages in thread
From: Mike Galbraith @ 2013-07-01 9:20 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: LKML, Ingo Molnar
On Mon, 2013-07-01 at 11:12 +0200, Mike Galbraith wrote:
> On Mon, 2013-07-01 at 10:06 +0200, Peter Zijlstra wrote:
>
> > So aside from the context tracking stuff, there's still a regression
> > we might want to look at. That's still a ~10% drop against 2.6.32 for
> > TCP_RR and few percents for tbench.
>
> Yeah, known, and some of it's ours.
(btw tbench has a ~5% phase-of-moon jitter, you can pretty much
disregard that one)
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-07-01 9:20 ` Mike Galbraith
@ 2013-07-02 4:03 ` Mike Galbraith
2013-07-02 7:19 ` Mike Galbraith
0 siblings, 1 reply; 8+ messages in thread
From: Mike Galbraith @ 2013-07-02 4:03 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: LKML, Ingo Molnar
On Mon, 2013-07-01 at 11:20 +0200, Mike Galbraith wrote:
> On Mon, 2013-07-01 at 11:12 +0200, Mike Galbraith wrote:
> > On Mon, 2013-07-01 at 10:06 +0200, Peter Zijlstra wrote:
> >
> > > So aside from the context tracking stuff, there's still a regression
> > > we might want to look at. That's still a ~10% drop against 2.6.32 for
> > > TCP_RR and few percents for tbench.
> >
> > Yeah, known, and some of it's ours.
>
> (btw tbench has a ~5% phase-of-moon jitter, you can pretty much
> disregard that one)
Hm. Seems we don't own much of TCP_RR regression after all, somewhere
along the line while my silly-tester hat was moldering, we got some
cycles back.. in the light config case anyway.
With wakeup granularity set to zero, per pipe-test, scheduler is within
variance of .32, sometimes appearing a tad lighter, though usually a wee
bit heavier. TCP_RR throughput delta does not correlate.
echo 0 > sched_wakeup_granularity_ns
pipe-test
2.6.32-regress 689.8 Khz 1.000
3.10.0-regress 682.5 Khz .989
netperf TCP_RR
2.6.32-regress 117910.11 Trans/sec 1.000
3.10.0-regress 96955.12 Trans/sec .822
It should be closer than this.
3.10.0-regress 2.6.32-regress
3.85% [kernel] [k] tcp_ack 4.04% [kernel] [k] tcp_sendmsg
3.34% [kernel] [k] __schedule 3.63% [kernel] [k] schedule
2.93% [kernel] [k] tcp_sendmsg 2.86% [kernel] [k] tcp_recvmsg
2.54% [kernel] [k] tcp_rcv_established 2.83% [kernel] [k] tcp_ack
2.26% [kernel] [k] tcp_transmit_skb 2.19% [kernel] [k] system_call
1.90% [kernel] [k] __netif_receive_skb_core 2.16% [kernel] [k] tcp_transmit_skb
1.87% [kernel] [k] tcp_v4_rcv 2.07% libc-2.14.1.so [.] __libc_recv
1.84% [kernel] [k] tcp_write_xmit 1.95% [kernel] [k] _spin_lock_bh
1.70% [kernel] [k] __switch_to 1.89% libc-2.14.1.so [.] __libc_send
1.57% [kernel] [k] tcp_recvmsg 1.77% [kernel] [k] tcp_rcv_established
1.54% [kernel] [k] _raw_spin_lock_bh 1.70% [kernel] [k] netif_receive_skb
1.52% libc-2.14.1.so [.] __libc_recv 1.61% [kernel] [k] tcp_v4_rcv
1.43% [kernel] [k] ip_rcv 1.49% [kernel] [k] native_sched_clock
1.35% [kernel] [k] local_bh_enable 1.49% [kernel] [k] tcp_write_xmit
1.33% [kernel] [k] _raw_spin_lock_irqsave 1.46% [kernel] [k] __switch_to
1.26% [kernel] [k] ip_queue_xmit 1.35% [kernel] [k] dev_queue_xmit
1.16% [kernel] [k] __inet_lookup_established 1.29% [kernel] [k] __alloc_skb
1.14% [kernel] [k] mod_timer 1.27% [kernel] [k] skb_release_data
1.13% [kernel] [k] process_backlog 1.26% netserver [.] recv_tcp_rr
1.13% [kernel] [k] read_tsc 1.22% [kernel] [k] local_bh_enable
1.13% libc-2.14.1.so [.] __libc_send 1.18% netperf [.] send_tcp_rr
1.12% [kernel] [k] system_call 1.18% [kernel] [k] sched_clock_local
1.07% [kernel] [k] tcp_event_data_recv 1.11% [kernel] [k] copy_user_generic_string
1.04% [kernel] [k] ip_finish_output 1.07% [kernel] [k] _spin_lock_irqsave
-Mike
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: sched: context tracking demolishes pipe-test
2013-07-02 4:03 ` Mike Galbraith
@ 2013-07-02 7:19 ` Mike Galbraith
0 siblings, 0 replies; 8+ messages in thread
From: Mike Galbraith @ 2013-07-02 7:19 UTC (permalink / raw)
To: Peter Zijlstra; +Cc: LKML, Ingo Molnar, netdev
CCs net-wizards since staring at profile/annotation isn't helping, and I
know all too well how these things laugh perversely at bisection.
On Tue, 2013-07-02 at 06:03 +0200, Mike Galbraith wrote:
> On Mon, 2013-07-01 at 11:20 +0200, Mike Galbraith wrote:
> > On Mon, 2013-07-01 at 11:12 +0200, Mike Galbraith wrote:
> > > On Mon, 2013-07-01 at 10:06 +0200, Peter Zijlstra wrote:
> > >
> > > > So aside from the context tracking stuff, there's still a regression
> > > > we might want to look at. That's still a ~10% drop against 2.6.32 for
> > > > TCP_RR and few percents for tbench.
> > >
> > > Yeah, known, and some of it's ours.
> >
> > (btw tbench has a ~5% phase-of-moon jitter, you can pretty much
> > disregard that one)
>
> Hm. Seems we don't own much of TCP_RR regression after all, somewhere
> along the line while my silly-tester hat was moldering, we got some
> cycles back.. in the light config case anyway.
>
> With wakeup granularity set to zero, per pipe-test, scheduler is within
> variance of .32, sometimes appearing a tad lighter, though usually a wee
> bit heavier. TCP_RR throughput delta does not correlate.
>
> echo 0 > sched_wakeup_granularity_ns
>
> pipe-test
> 2.6.32-regress 689.8 Khz 1.000
> 3.10.0-regress 682.5 Khz .989
>
> netperf TCP_RR
> 2.6.32-regress 117910.11 Trans/sec 1.000
> 3.10.0-regress 96955.12 Trans/sec .822
>
> It should be closer than this.
>
> 3.10.0-regress 2.6.32-regress
> 3.85% [kernel] [k] tcp_ack 4.04% [kernel] [k] tcp_sendmsg
> 3.34% [kernel] [k] __schedule 3.63% [kernel] [k] schedule
> 2.93% [kernel] [k] tcp_sendmsg 2.86% [kernel] [k] tcp_recvmsg
> 2.54% [kernel] [k] tcp_rcv_established 2.83% [kernel] [k] tcp_ack
> 2.26% [kernel] [k] tcp_transmit_skb 2.19% [kernel] [k] system_call
> 1.90% [kernel] [k] __netif_receive_skb_core 2.16% [kernel] [k] tcp_transmit_skb
> 1.87% [kernel] [k] tcp_v4_rcv 2.07% libc-2.14.1.so [.] __libc_recv
> 1.84% [kernel] [k] tcp_write_xmit 1.95% [kernel] [k] _spin_lock_bh
> 1.70% [kernel] [k] __switch_to 1.89% libc-2.14.1.so [.] __libc_send
> 1.57% [kernel] [k] tcp_recvmsg 1.77% [kernel] [k] tcp_rcv_established
> 1.54% [kernel] [k] _raw_spin_lock_bh 1.70% [kernel] [k] netif_receive_skb
> 1.52% libc-2.14.1.so [.] __libc_recv 1.61% [kernel] [k] tcp_v4_rcv
> 1.43% [kernel] [k] ip_rcv 1.49% [kernel] [k] native_sched_clock
> 1.35% [kernel] [k] local_bh_enable 1.49% [kernel] [k] tcp_write_xmit
> 1.33% [kernel] [k] _raw_spin_lock_irqsave 1.46% [kernel] [k] __switch_to
> 1.26% [kernel] [k] ip_queue_xmit 1.35% [kernel] [k] dev_queue_xmit
> 1.16% [kernel] [k] __inet_lookup_established 1.29% [kernel] [k] __alloc_skb
> 1.14% [kernel] [k] mod_timer 1.27% [kernel] [k] skb_release_data
> 1.13% [kernel] [k] process_backlog 1.26% netserver [.] recv_tcp_rr
> 1.13% [kernel] [k] read_tsc 1.22% [kernel] [k] local_bh_enable
> 1.13% libc-2.14.1.so [.] __libc_send 1.18% netperf [.] send_tcp_rr
> 1.12% [kernel] [k] system_call 1.18% [kernel] [k] sched_clock_local
> 1.07% [kernel] [k] tcp_event_data_recv 1.11% [kernel] [k] copy_user_generic_string
> 1.04% [kernel] [k] ip_finish_output 1.07% [kernel] [k] _spin_lock_irqsave
>
> -Mike
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2013-07-02 7:20 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2013-06-30 7:57 sched: context tracking demolishes pipe-test Mike Galbraith
2013-06-30 21:29 ` Peter Zijlstra
2013-07-01 6:07 ` Mike Galbraith
2013-07-01 8:06 ` Peter Zijlstra
2013-07-01 9:12 ` Mike Galbraith
2013-07-01 9:20 ` Mike Galbraith
2013-07-02 4:03 ` Mike Galbraith
2013-07-02 7:19 ` Mike Galbraith
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox