Can someone tell me how I'm being confused?
I ran the following command as root:
perf stat schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild
This runs e2fsck under perf, with the cpu affinity nailed to a single
CPU. I therefore expected the CPU-migrations field reported by perf to
be 0. That was not what I found, though:
Performance counter stats for 'schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild':
1169.715766 task-clock-msecs # 0.180 CPUs
9212 context-switches # 0.008 M/sec
307 CPU-migrations # 0.000 M/sec
1875 page-faults # 0.002 M/sec
2737168498 cycles # 2340.029 M/sec
3125632038 instructions # 1.142 IPC
688556730 branches # 588.653 M/sec
7263580 branch-misses # 1.055 %
15222417 cache-references # 13.014 M/sec
1488633 cache-misses # 1.273 M/sec
6.481483548 seconds time elapsed
How could this be? The CPU-migrations event counter only gets
incremented if a task changes CPU's, as seen in kernel/sched.c:
if (task_cpu(p) != new_cpu) {
p->se.nr_migrations++;
perf_sw_event(PERF_COUNT_SW_CPU_MIGRATIONS, 1, 1, NULL, 0);
}
So it should be 0, not 307, right? What am I missing?
- Ted
On Thu, Jun 16, 2011 at 10:46:26AM -0400, Theodore Ts'o wrote:
> Can someone tell me how I'm being confused?
>
> I ran the following command as root:
>
> perf stat schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild
A theory is that schedtool does:
if (!fork()) {
set affinity there
launch e2fsck
}
So schedtool as a parent doesn't change it's own affinity, which makes sense
as you only want to set it for the child.
By the time it is launched, do mmap, faults, etc... and after the wait()
finishes and it exits(). It has got many opportunities to migrate.
>
> This runs e2fsck under perf, with the cpu affinity nailed to a single
> CPU. I therefore expected the CPU-migrations field reported by perf to
> be 0. That was not what I found, though:
>
> Performance counter stats for 'schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild':
>
> 1169.715766 task-clock-msecs # 0.180 CPUs
> 9212 context-switches # 0.008 M/sec
> 307 CPU-migrations # 0.000 M/sec
> 1875 page-faults # 0.002 M/sec
> 2737168498 cycles # 2340.029 M/sec
> 3125632038 instructions # 1.142 IPC
> 688556730 branches # 588.653 M/sec
> 7263580 branch-misses # 1.055 %
> 15222417 cache-references # 13.014 M/sec
> 1488633 cache-misses # 1.273 M/sec
>
> 6.481483548 seconds time elapsed
>
> How could this be? The CPU-migrations event counter only gets
> incremented if a task changes CPU's, as seen in kernel/sched.c:
>
> if (task_cpu(p) != new_cpu) {
> p->se.nr_migrations++;
> perf_sw_event(PERF_COUNT_SW_CPU_MIGRATIONS, 1, 1, NULL, 0);
> }
>
> So it should be 0, not 307, right? What am I missing?
>
> - Ted
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
On 16/06/11 16:03, Frederic Weisbecker wrote:
> On Thu, Jun 16, 2011 at 10:46:26AM -0400, Theodore Ts'o wrote:
>> Can someone tell me how I'm being confused?
>>
>> I ran the following command as root:
>>
>> perf stat schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild
>
> A theory is that schedtool does:
>
> if (!fork()) {
> set affinity there
> launch e2fsck
> }
Well `taskset` and `chrt` from util-linux don't fork at least,
so you could try those instead.
I also suggest protecting the command with --
in case perf is not stopping at the first unrecognized option.
cheers,
P?draig.
On Thu, Jun 16, 2011 at 04:11:03PM +0100, P?draig Brady wrote:
> On 16/06/11 16:03, Frederic Weisbecker wrote:
> > On Thu, Jun 16, 2011 at 10:46:26AM -0400, Theodore Ts'o wrote:
> >> Can someone tell me how I'm being confused?
> >>
> >> I ran the following command as root:
> >>
> >> perf stat schedtool -a 1 -e e2fsck -ft /dev/funarg/kbuild
> >
> > A theory is that schedtool does:
> >
> > if (!fork()) {
> > set affinity there
> > launch e2fsck
> > }
>
> Well `taskset` and `chrt` from util-linux don't fork at least,
> so you could try those instead.
Even if they don't fork and change their own affinity, you'll get
migrations that happened since taskset/chrt were launched.
The only solution is too set perf affinity itself:
schedtool -a 1 -e perf stat -- e2fsck -ft /dev/funarg/kbuild
Taskset would work too.
>
> I also suggest protecting the command with --
> in case perf is not stopping at the first unrecognized option.
>
> cheers,
> P?draig.
On Thu, Jun 16, 2011 at 05:18:39PM +0200, Frederic Weisbecker wrote:
> The only solution is too set perf affinity itself:
>
> schedtool -a 1 -e perf stat -- e2fsck -ft /dev/funarg/kbuild
Nope, that doesn't solve the problem:
# schedtool -a 1 -e perf stat -- e2fsck -ft /dev/funarg/kbuild
e2fsck 1.41.14 (22-Dec-2010)
Pass 1: Checking inodes, blocks, and sizes
Pass 2: Checking directory structure
Pass 3: Checking directory connectivity
Pass 4: Checking reference counts
Pass 5: Checking group summary information
/dev/funarg/kbuild: 223466/1638400 files (0.3% non-contiguous), 4915668/6553600 blocks
Memory used: 2600k/0k (1069k/1532k), time: 6.72/ 1.18/ 0.36
I/O read: 137MB, write: 1MB, rate: 20.38MB/s
Performance counter stats for 'e2fsck -ft /dev/funarg/kbuild':
1523.616797 task-clock # 0.224 CPUs utilized
7227 context-switches # 0.005 M/sec
253 CPU-migrations # 0.000 M/sec
1936 page-faults # 0.001 M/sec
4176409631 cycles # 2.741 GHz
<not counted> stalled-cycles-frontend
<not counted> stalled-cycles-backend
4828485353 instructions # 1.16 insns per cycle
877742160 branches # 576.091 M/sec
8017490 branch-misses # 0.91% of all branches
6.798746204 seconds time elapsed
Note the 253 CPU migration....
- Ted
On 06/16/2011 08:44 PM, Ted Ts'o wrote:
> On Thu, Jun 16, 2011 at 05:18:39PM +0200, Frederic Weisbecker wrote:
>> The only solution is too set perf affinity itself:
>>
>> schedtool -a 1 -e perf stat -- e2fsck -ft /dev/funarg/kbuild
I don't have schedtool, but I was able to repeat it with taskset:
taskset -pc 2 $$
perf stat -- e2fsck -ft <device>
where <device> is a 400G ext4 partition. First time through perf-stat
showed a number of migrations over the 134 second window. e2fsck runs
much quicker after the initial one, and migrations aren't showing up as
easily.
Try this:
perf record -Tg -e migrations -fo /tmp/perf.data -- schedtool -a 1 -e
perf stat -- e2fsck -ft /dev/funarg/kbuild
The outer perf-record will capture when the migrations occur. If you
don't mind recompiling perf, modify tools/perf/builtin-record.c and
force the capture of the cpu id on the samples. In config_attr() you want:
attr->sample_type |= PERF_SAMPLE_CPU;
On the captured data file run:
perf script -i /tmp/perf.data
You'll see something like this (captured on a run where I was able to
get 2 migrations):
e2fsck 2069 [002] 210.671401: CPU-migrations:
ffffffff81045a7b set_task_cpu ([kern
e2fsck 2069 [002] 213.675785: CPU-migrations:
ffffffff81045a7b set_task_cpu ([kern
David
>
> Nope, that doesn't solve the problem:
>
> # schedtool -a 1 -e perf stat -- e2fsck -ft /dev/funarg/kbuild
> e2fsck 1.41.14 (22-Dec-2010)
> Pass 1: Checking inodes, blocks, and sizes
> Pass 2: Checking directory structure
> Pass 3: Checking directory connectivity
> Pass 4: Checking reference counts
> Pass 5: Checking group summary information
> /dev/funarg/kbuild: 223466/1638400 files (0.3% non-contiguous), 4915668/6553600 blocks
> Memory used: 2600k/0k (1069k/1532k), time: 6.72/ 1.18/ 0.36
> I/O read: 137MB, write: 1MB, rate: 20.38MB/s
>
> Performance counter stats for 'e2fsck -ft /dev/funarg/kbuild':
>
> 1523.616797 task-clock # 0.224 CPUs utilized
> 7227 context-switches # 0.005 M/sec
> 253 CPU-migrations # 0.000 M/sec
> 1936 page-faults # 0.001 M/sec
> 4176409631 cycles # 2.741 GHz
> <not counted> stalled-cycles-frontend
> <not counted> stalled-cycles-backend
> 4828485353 instructions # 1.16 insns per cycle
> 877742160 branches # 576.091 M/sec
> 8017490 branch-misses # 0.91% of all branches
>
> 6.798746204 seconds time elapsed
>
> Note the 253 CPU migration....
>
> - Ted
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/