* [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).