* [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops
@ 2014-05-15 4:50 Jet Chen
2014-05-15 4:55 ` Tejun Heo
0 siblings, 1 reply; 6+ messages in thread
From: Jet Chen @ 2014-05-15 4:50 UTC (permalink / raw)
To: Tejun Heo; +Cc: Fengguang Wu, LKML, lkp
[-- Attachment #1: Type: text/plain, Size: 1206 bytes --]
Hi Tejun,
FYI, we noticed the below changes on
git://git.kernel.org/pub/scm/linux/kernel/git/tj/cgroup.git review-kill-tree_mutex
commit a0f9ec1f181534694cb5bf40b7b56515b8cabef9 ("cgroup: use cgroup_kn_lock_live() in other cgroup kernfs methods")
Test case : lkp-nex05/will-it-scale/writeseek
2074b6e38668e62 a0f9ec1f181534694cb5bf40b
--------------- -------------------------
1027273 ~ 0% -4.3% 982732 ~ 0% TOTAL will-it-scale.per_thread_ops
136 ~ 3% -43.1% 77 ~43% TOTAL proc-vmstat.nr_dirtied
0.51 ~ 3% +98.0% 1.01 ~ 4% TOTAL perf-profile.cpu-cycles.shmem_write_end.generic_perform_write.__generic_file_aio_write.generic_file_aio_write.do_sync_write
1078 ~ 9% -16.3% 903 ~11% TOTAL numa-meminfo.node0.Unevictable
269 ~ 9% -16.2% 225 ~11% TOTAL numa-vmstat.node0.nr_unevictable
1.64 ~ 1% -14.3% 1.41 ~ 4% TOTAL perf-profile.cpu-cycles.find_lock_entry.shmem_getpage_gfp.shmem_write_begin.generic_perform_write.__generic_file_aio_write
1.62 ~ 2% +14.1% 1.84 ~ 1% TOTAL perf-profile.cpu-cycles.lseek64
Legend:
~XX% - stddev percent
[+-]XX% - change percent
Thanks,
Jet
[-- Attachment #2: reproduce --]
[-- Type: text/plain, Size: 4771 bytes --]
echo performance > /sys/devices/system/cpu/cpu0/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu1/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu10/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu11/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu12/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu13/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu14/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu15/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu16/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu17/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu18/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu19/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu2/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu20/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu21/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu22/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu23/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu24/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu25/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu26/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu27/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu28/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu29/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu3/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu30/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu31/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu32/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu33/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu34/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu35/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu36/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu37/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu38/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu39/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu4/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu40/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu41/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu42/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu43/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu44/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu45/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu46/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu47/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu48/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu49/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu5/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu50/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu51/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu52/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu53/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu54/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu55/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu56/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu57/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu58/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu59/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu6/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu60/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu61/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu62/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu63/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu7/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu8/cpufreq/scaling_governor
echo performance > /sys/devices/system/cpu/cpu9/cpufreq/scaling_governor
./runtest.py writeseek 20 1 10 20 30 48 64
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops 2014-05-15 4:50 [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops Jet Chen @ 2014-05-15 4:55 ` Tejun Heo 2014-05-15 6:00 ` Fengguang Wu 0 siblings, 1 reply; 6+ messages in thread From: Tejun Heo @ 2014-05-15 4:55 UTC (permalink / raw) To: Jet Chen; +Cc: Fengguang Wu, LKML, lkp Hello, On Thu, May 15, 2014 at 12:50:39PM +0800, Jet Chen wrote: > FYI, we noticed the below changes on > > git://git.kernel.org/pub/scm/linux/kernel/git/tj/cgroup.git review-kill-tree_mutex > commit a0f9ec1f181534694cb5bf40b7b56515b8cabef9 ("cgroup: use cgroup_kn_lock_live() in other cgroup kernfs methods") > > Test case : lkp-nex05/will-it-scale/writeseek > > 2074b6e38668e62 a0f9ec1f181534694cb5bf40b > --------------- ------------------------- > 1027273 ~ 0% -4.3% 982732 ~ 0% TOTAL will-it-scale.per_thread_ops > 136 ~ 3% -43.1% 77 ~43% TOTAL proc-vmstat.nr_dirtied > 0.51 ~ 3% +98.0% 1.01 ~ 4% TOTAL perf-profile.cpu-cycles.shmem_write_end.generic_perform_write.__generic_file_aio_write.generic_file_aio_write.do_sync_write > 1078 ~ 9% -16.3% 903 ~11% TOTAL numa-meminfo.node0.Unevictable > 269 ~ 9% -16.2% 225 ~11% TOTAL numa-vmstat.node0.nr_unevictable > 1.64 ~ 1% -14.3% 1.41 ~ 4% TOTAL perf-profile.cpu-cycles.find_lock_entry.shmem_getpage_gfp.shmem_write_begin.generic_perform_write.__generic_file_aio_write > 1.62 ~ 2% +14.1% 1.84 ~ 1% TOTAL perf-profile.cpu-cycles.lseek64 I have no idea how to read the above. Which direction is plus and which is minus? Are they counting cpu cycles? Which files is the test seeking? Thanks. -- tejun ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops 2014-05-15 4:55 ` Tejun Heo @ 2014-05-15 6:00 ` Fengguang Wu 2014-05-15 6:14 ` Tejun Heo 0 siblings, 1 reply; 6+ messages in thread From: Fengguang Wu @ 2014-05-15 6:00 UTC (permalink / raw) To: Tejun Heo; +Cc: Jet Chen, LKML, lkp Hi Tejun, On Thu, May 15, 2014 at 12:55:17AM -0400, Tejun Heo wrote: > Hello, > > On Thu, May 15, 2014 at 12:50:39PM +0800, Jet Chen wrote: > > FYI, we noticed the below changes on > > > > git://git.kernel.org/pub/scm/linux/kernel/git/tj/cgroup.git review-kill-tree_mutex > > commit a0f9ec1f181534694cb5bf40b7b56515b8cabef9 ("cgroup: use cgroup_kn_lock_live() in other cgroup kernfs methods") > > > > Test case : lkp-nex05/will-it-scale/writeseek > > > > 2074b6e38668e62 a0f9ec1f181534694cb5bf40b > > --------------- ------------------------- 2074b6e38668e62 is the base of comparison. So "-4.3% will-it-scale.per_thread_ops" in the below line means a0f9ec1f18 has lower will-it-scale throughput. > > 1027273 ~ 0% -4.3% 982732 ~ 0% TOTAL will-it-scale.per_thread_ops > > 136 ~ 3% -43.1% 77 ~43% TOTAL proc-vmstat.nr_dirtied > > 0.51 ~ 3% +98.0% 1.01 ~ 4% TOTAL perf-profile.cpu-cycles.shmem_write_end.generic_perform_write.__generic_file_aio_write.generic_file_aio_write.do_sync_write > > 1078 ~ 9% -16.3% 903 ~11% TOTAL numa-meminfo.node0.Unevictable > > 269 ~ 9% -16.2% 225 ~11% TOTAL numa-vmstat.node0.nr_unevictable > > 1.64 ~ 1% -14.3% 1.41 ~ 4% TOTAL perf-profile.cpu-cycles.find_lock_entry.shmem_getpage_gfp.shmem_write_begin.generic_perform_write.__generic_file_aio_write > > 1.62 ~ 2% +14.1% 1.84 ~ 1% TOTAL perf-profile.cpu-cycles.lseek64 The perf-profile.cpu-cycles.* lines are from "perf record/report". The last line shows that lseek64() takes 1.62% CPU cycles for commit 2074b6e38668e62 and that percent increased by +14.1% on a0f9ec1f181. One of the raw perf record output is 1.84% writeseek_proce libc-2.17.so [.] lseek64 | --- lseek64 There are 5 runs and 1.62% is the average value. > I have no idea how to read the above. Which direction is plus and > which is minus? Are they counting cpu cycles? Which files is the > test seeking? It's tmpfs files. Because the will-it-scale test case is mean to measure scalability of syscalls. We do not use HDD/SSD etc. storage devices when running it. The will-it-scale/writeseek test code is char *testcase_description = "Separate file seek+write"; void testcase(unsigned long long *iterations) { char buf[BUFLEN]; char tmpfile[] = "/tmp/willitscale.XXXXXX"; int fd = mkstemp(tmpfile); memset(buf, 0, sizeof(buf)); assert(fd >= 0); unlink(tmpfile); while (1) { lseek(fd, 0, SEEK_SET); assert(write(fd, buf, BUFLEN) == BUFLEN); (*iterations)++; } } Thanks, Fengguang ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops 2014-05-15 6:00 ` Fengguang Wu @ 2014-05-15 6:14 ` Tejun Heo 2014-05-15 7:11 ` Mike Galbraith 2014-05-15 8:16 ` Fengguang Wu 0 siblings, 2 replies; 6+ messages in thread From: Tejun Heo @ 2014-05-15 6:14 UTC (permalink / raw) To: Fengguang Wu; +Cc: Jet Chen, LKML, lkp Hello, Fengguang. On Thu, May 15, 2014 at 02:00:26PM +0800, Fengguang Wu wrote: > > > 2074b6e38668e62 a0f9ec1f181534694cb5bf40b > > > --------------- ------------------------- > > 2074b6e38668e62 is the base of comparison. So "-4.3% will-it-scale.per_thread_ops" > in the below line means a0f9ec1f18 has lower will-it-scale throughput. > > > > 1027273 ~ 0% -4.3% 982732 ~ 0% TOTAL will-it-scale.per_thread_ops > > > 136 ~ 3% -43.1% 77 ~43% TOTAL proc-vmstat.nr_dirtied > > > 0.51 ~ 3% +98.0% 1.01 ~ 4% TOTAL perf-profile.cpu-cycles.shmem_write_end.generic_perform_write.__generic_file_aio_write.generic_file_aio_write.do_sync_write > > > 1078 ~ 9% -16.3% 903 ~11% TOTAL numa-meminfo.node0.Unevictable > > > 269 ~ 9% -16.2% 225 ~11% TOTAL numa-vmstat.node0.nr_unevictable > > > 1.64 ~ 1% -14.3% 1.41 ~ 4% TOTAL perf-profile.cpu-cycles.find_lock_entry.shmem_getpage_gfp.shmem_write_begin.generic_perform_write.__generic_file_aio_write > > > 1.62 ~ 2% +14.1% 1.84 ~ 1% TOTAL perf-profile.cpu-cycles.lseek64 > > The perf-profile.cpu-cycles.* lines are from "perf record/report". > > The last line shows that lseek64() takes 1.62% CPU cycles for > commit 2074b6e38668e62 and that percent increased by +14.1% on > a0f9ec1f181. One of the raw perf record output is > > 1.84% writeseek_proce libc-2.17.so [.] lseek64 > | > --- lseek64 > > There are 5 runs and 1.62% is the average value. > > > I have no idea how to read the above. Which direction is plus and > > which is minus? Are they counting cpu cycles? Which files is the > > test seeking? > > It's tmpfs files. Because the will-it-scale test case is mean to > measure scalability of syscalls. We do not use HDD/SSD etc. storage > devices when running it. Hmmm... I'm completely stumped. The commit in question has nothing to do with tmpfs. It only affects three cgroup files - "tasks", "cgroup.procs" and "release_agent". It can't possibly have any effect on tmpfs operation. Maybe random effect through code alignment? Even that is highly unlikely. I'll look into it tomorrow but can you please try to repeat the test? It really doesn't make any sense to me. Thanks. -- tejun ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops 2014-05-15 6:14 ` Tejun Heo @ 2014-05-15 7:11 ` Mike Galbraith 2014-05-15 8:16 ` Fengguang Wu 1 sibling, 0 replies; 6+ messages in thread From: Mike Galbraith @ 2014-05-15 7:11 UTC (permalink / raw) To: Tejun Heo; +Cc: Fengguang Wu, Jet Chen, LKML, lkp On Thu, 2014-05-15 at 02:14 -0400, Tejun Heo wrote: > Hmmm... I'm completely stumped. The commit in question has nothing to > do with tmpfs. It only affects three cgroup files - "tasks", > "cgroup.procs" and "release_agent". It can't possibly have any effect > on tmpfs operation. Maybe random effect through code alignment? Even > that is highly unlikely. Unlikely, but it happens. I bisected a tbench regression down to a completely unrelated driver change, and watched it repeatably drop throughput 5% despite skeptical "No way, show me that trick again". -Mike ^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops 2014-05-15 6:14 ` Tejun Heo 2014-05-15 7:11 ` Mike Galbraith @ 2014-05-15 8:16 ` Fengguang Wu 1 sibling, 0 replies; 6+ messages in thread From: Fengguang Wu @ 2014-05-15 8:16 UTC (permalink / raw) To: Tejun Heo; +Cc: Jet Chen, LKML, lkp On Thu, May 15, 2014 at 02:14:22AM -0400, Tejun Heo wrote: > Hello, Fengguang. > > On Thu, May 15, 2014 at 02:00:26PM +0800, Fengguang Wu wrote: > > > > 2074b6e38668e62 a0f9ec1f181534694cb5bf40b > > > > --------------- ------------------------- > > > > 2074b6e38668e62 is the base of comparison. So "-4.3% will-it-scale.per_thread_ops" > > in the below line means a0f9ec1f18 has lower will-it-scale throughput. > > > > > > 1027273 ~ 0% -4.3% 982732 ~ 0% TOTAL will-it-scale.per_thread_ops > > > > 136 ~ 3% -43.1% 77 ~43% TOTAL proc-vmstat.nr_dirtied > > > > 0.51 ~ 3% +98.0% 1.01 ~ 4% TOTAL perf-profile.cpu-cycles.shmem_write_end.generic_perform_write.__generic_file_aio_write.generic_file_aio_write.do_sync_write > > > > 1078 ~ 9% -16.3% 903 ~11% TOTAL numa-meminfo.node0.Unevictable > > > > 269 ~ 9% -16.2% 225 ~11% TOTAL numa-vmstat.node0.nr_unevictable > > > > 1.64 ~ 1% -14.3% 1.41 ~ 4% TOTAL perf-profile.cpu-cycles.find_lock_entry.shmem_getpage_gfp.shmem_write_begin.generic_perform_write.__generic_file_aio_write > > > > 1.62 ~ 2% +14.1% 1.84 ~ 1% TOTAL perf-profile.cpu-cycles.lseek64 > > > > The perf-profile.cpu-cycles.* lines are from "perf record/report". > > > > The last line shows that lseek64() takes 1.62% CPU cycles for > > commit 2074b6e38668e62 and that percent increased by +14.1% on > > a0f9ec1f181. One of the raw perf record output is > > > > 1.84% writeseek_proce libc-2.17.so [.] lseek64 > > | > > --- lseek64 > > > > There are 5 runs and 1.62% is the average value. > > > > > I have no idea how to read the above. Which direction is plus and > > > which is minus? Are they counting cpu cycles? Which files is the > > > test seeking? > > > > It's tmpfs files. Because the will-it-scale test case is mean to > > measure scalability of syscalls. We do not use HDD/SSD etc. storage > > devices when running it. > > Hmmm... I'm completely stumped. The commit in question has nothing to > do with tmpfs. It only affects three cgroup files - "tasks", > "cgroup.procs" and "release_agent". It can't possibly have any effect > on tmpfs operation. Maybe random effect through code alignment? Even > that is highly unlikely. I'll look into it tomorrow but can you > please try to repeat the test? It really doesn't make any sense to > me. Yes, sorry! Even though the "first bad" commit a0f9ec1f1 and its parent commit 2074b6e38 has clear and stable performance changes: 5 runs of a0f9ec1f1: "will-it-scale.per_thread_ops": [ 983098, 985112, 982690, 976157, 986606 ], 5 runs of 2074b6e38: "will-it-scale.per_thread_ops": [ 1027667, 1029414, 1026736, 1025678, 1026871 ], Comparing the bisect-good and bisect-bad *kernels*, you'll find the performance changes are not as stable: will-it-scale.per_thread_ops 1.14e+06 ++---------------------------------------------------------------+ 1.12e+06 ++ *.. | | : * | 1.1e+06 ++ : : | 1.08e+06 ++ : : | | : : | 1.06e+06 ++ : : | 1.04e+06 *+.*...*..*..*..*...*..*.. : : ..*..*.. | 1.02e+06 ++ O *..* *..*. *..*...*..*..* | O O | 1e+06 O+ O O O O O | 980000 ++ O O O O O O O | | | 960000 ++ O O | 940000 ++---------------------------------------------------------------+ [*] bisect-good sample [O] bisect-bad sample So it might be some subtle data padding/alignment issue. Thanks, Fengguang ^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2014-05-15 8:16 UTC | newest] Thread overview: 6+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2014-05-15 4:50 [cgroup] a0f9ec1f181: -4.3% will-it-scale.per_thread_ops Jet Chen 2014-05-15 4:55 ` Tejun Heo 2014-05-15 6:00 ` Fengguang Wu 2014-05-15 6:14 ` Tejun Heo 2014-05-15 7:11 ` Mike Galbraith 2014-05-15 8:16 ` Fengguang Wu
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).