perf_counters issue with enable_on_exec

perf_counters issue with enable_on_exec

[stephane eranian]

Hi,

I am running into an issue trying to use enable_on_exec
in per-thread mode with an event group.

My understanding is that enable_on_exec allows activation
of an event on first exec. This is useful for tools monitoring
other tasks and which you invoke as: tool my_program. In
other words, the tool forks+execs my_program. This option
allows developers to setup the events after the fork (to get
the pid) but before the exec(). Only execution after the exec
is monitored. This alleviates the need to use the
ptrace(PTRACE_TRACEME) call.

My understanding is that an event group is scheduled only
if all events in the group are active (disabled=0). Thus, one
trick to activate a group  with a single ioctl(PERF_IOC_ENABLE)
is to enable all events in the group except the leader. This works
well. But once you add enable_on_exec on on the events,
things go wrong. The non-leader events start counting before
the exec. If the non-leader events are created in disabled state,
then they never activate on exec.

The attached test program demonstrates the problem.
simply invoke with a program that runs for a few seconds.


#include <sys/types.h>
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>
#include <unistd.h>
#include <string.h>
#include <sys/wait.h>
#include <syscall.h>
#include <err.h>

#include <perf_counter.h>

int
child(char **arg)
{
	int i;

	/* burn cycles to detect if monitoring start before exec */
	for(i=0; i < 5000000; i++) syscall(__NR_getpid);
	execvp(arg[0], arg);
	errx(1, "cannot exec: %s\n", arg[0]);
	/* not reached */
}

int
parent(char **arg)
{
	struct perf_counter_attr hw[2];
	char *name[2];
	int fd[2];
	int status, ret, i;
	uint64_t values[3];
	pid_t pid;

	if ((pid=fork()) == -1)
		err(1, "Cannot fork process");


	memset(hw, 0, sizeof(hw));

	name[0] = "PERF_COUNT_HW_CPU_CYCLES";
	hw[0].type = PERF_TYPE_HARDWARE;
	hw[0].config = PERF_COUNT_HW_CPU_CYCLES;
	hw[0].read_format =
PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
	hw[0].disabled = 1;
	hw[0].enable_on_exec = 1;

	name[1] = "PERF_COUNT_HW_INSTRUCTIONS";
	hw[1].type = PERF_TYPE_HARDWARE;
	hw[1].config = PERF_COUNT_HW_INSTRUCTIONS;
	hw[1].read_format =
PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
	hw[1].disabled = 0;
	hw[1].enable_on_exec = 1;

	fd[0] = perf_counter_open(&hw[0], pid, -1, -1, 0);
	if (fd[0] == -1)
		err(1, "cannot open event0");

	fd[1] = perf_counter_open(&hw[1], pid, -1, fd[0], 0);
	if (fd[1] == -1)
		err(1, "cannot open event1");

	if (pid == 0)
		exit(child(arg));

	waitpid(pid, &status, 0);

	for(i=0; i < 2; i++) {
		ret = read(fd[i], values, sizeof(values));
		if (ret < sizeof(values))
			err(1, "cannot read values event %s", name[i]);
		if (values[2])
			values[0] = (uint64_t)((double)values[0] * values[1]/values[2]);

		printf("%20"PRIu64" %s %s\n",
			values[0],
			name[i],
			values[1] != values[2] ? "(scaled)" : "");

		close(fd[i]);
	}
	return 0;
}

int
main(int argc, char **argv)
{
	if (!argv[1])
		errx(1, "you must specify a command to execute\n");
	
	return parent(argv+1);
}

Re: perf_counters issue with enable_on_exec

[Peter Zijlstra]

On Thu, 2009-08-20 at 15:49 +0200, stephane eranian wrote:
> Hi,
> 
> I am running into an issue trying to use enable_on_exec
> in per-thread mode with an event group.
> 
> My understanding is that enable_on_exec allows activation
> of an event on first exec. This is useful for tools monitoring
> other tasks and which you invoke as: tool my_program. In
> other words, the tool forks+execs my_program. This option
> allows developers to setup the events after the fork (to get
> the pid) but before the exec(). Only execution after the exec
> is monitored. This alleviates the need to use the
> ptrace(PTRACE_TRACEME) call.
> 
> My understanding is that an event group is scheduled only
> if all events in the group are active (disabled=0). Thus, one
> trick to activate a group  with a single ioctl(PERF_IOC_ENABLE)
> is to enable all events in the group except the leader. This works
> well. But once you add enable_on_exec on on the events,
> things go wrong. The non-leader events start counting before
> the exec. If the non-leader events are created in disabled state,
> then they never activate on exec.
> 
> The attached test program demonstrates the problem.
> simply invoke with a program that runs for a few seconds.

OK, lots of issues here

 1) your code is broken ;-)
 2) enable_on_exec on !leader counters is undefined
 3) there is something fishy non the less


1. you fork() then create a counter group in both the parent and the
child without sync, then read the parent group. This obviously doesn't
do what is expected. See attached proglet for a better version.

2. enable_on_exec only works on leaders, Paul, was that intended?

3. the scale stuff seems broken

# perf stat -e cycles -e instructions --repeat 10 true

 Performance counter stats for 'true' (10 runs):

        2612124  cycles                     ( +-   1.327% )
        1870479  instructions             #      0.716 IPC     ( +-   0.132% )

    0.003743155  seconds time elapsed   ( +-   1.203% )

# ./test-enable_on_exec true
             2651600 PERF_COUNT_HW_CPU_CYCLES 1111509 1111509 2651600.000000
             1832720 PERF_COUNT_HW_INSTRUCTIONS 839395242 1111509 1384043177.264637

Paul, would a counter's time start running when its 'enabled' but part
of a non-runnable group?


---
#include "perf.h"

#include <sys/types.h>
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>
#include <unistd.h>
#include <string.h>
#include <sys/wait.h>
#include <syscall.h>
#include <err.h>
#include <fcntl.h>


int child(char **arg)
{
	int i;

	/* burn cycles to detect if monitoring start before exec */
	for(i=0; i < 5000000; i++) syscall(__NR_getpid);
	execvp(arg[0], arg);
	errx(1, "cannot exec: %s\n", arg[0]);
	/* not reached */
}

int parent(char **arg)
{
	struct perf_counter_attr hw[2];
	char *name[2];
	int fd[2];
	int status, ret, i;
	uint64_t values[3];
	pid_t pid;
	int child_ready_pipe[2], go_pipe[2];
	char buf;

	if (pipe(child_ready_pipe) < 0 || pipe(go_pipe) < 0) {
		perror("Failed to create pipes");
		exit(1);
	}

	if ((pid=fork()) == -1)
		err(1, "Cannot fork process");

	if (pid == 0) {
		close(child_ready_pipe[0]);
		close(go_pipe[1]);
		fcntl(go_pipe[0], F_SETFD, FD_CLOEXEC);

		execvp("", (char **)arg);

		/*
		 * let the parent know we exist
		 */
		close(child_ready_pipe[1]);

		/*
		 * wait for the parent to attach its counters
		 */
		if (read(go_pipe[0], &buf, 1) == -1)
			perror("unable to read go_pipe");

		exit(child(arg));
	}

	close(child_ready_pipe[1]);
	close(go_pipe[0]);
	/*
	 * wait for the child to appear
	 */
	if (read(child_ready_pipe[0], &buf, 1) == -1)
		perror("unable to read child_ready_pipe");
	close(child_ready_pipe[0]);

	memset(hw, 0, sizeof(hw));

	name[0] = "PERF_COUNT_HW_CPU_CYCLES";
	hw[0].type = PERF_TYPE_HARDWARE;
	hw[0].config = PERF_COUNT_HW_CPU_CYCLES;
	hw[0].read_format =
		PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
	hw[0].disabled = 1;
	hw[0].enable_on_exec = 1;

	name[1] = "PERF_COUNT_HW_INSTRUCTIONS";
	hw[1].type = PERF_TYPE_HARDWARE;
	hw[1].config = PERF_COUNT_HW_INSTRUCTIONS;
	hw[1].read_format =
		PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
	hw[1].disabled = 0;
	hw[1].enable_on_exec = 0;

	fd[0] = sys_perf_counter_open(&hw[0], pid, -1, -1, 0);
	if (fd[0] == -1)
		err(1, "cannot open event0");

	fd[1] = sys_perf_counter_open(&hw[1], pid, -1, fd[0], 0);
	if (fd[1] == -1)
		err(1, "cannot open event1");

	/*
	 * we're good to go, let the child rip
	 */
	close(go_pipe[1]);

	waitpid(pid, &status, 0);

	for(i=0; i < 2; i++) {
		ret = read(fd[i], values, sizeof(values));
		if (ret < sizeof(values))
			err(1, "cannot read values event %s", name[i]);

		printf("%20"PRIu64" %s %ld %ld %f\n",
				values[0],
				name[i],
				values[1], values[2],
			values[2] ? (double)values[0] * values[1]/values[2] : 0);

		close(fd[i]);
	}
	return 0;
}

int main(int argc, char **argv)
{
	if (!argv[1])
		errx(1, "you must specify a command to execute\n");

	return parent(argv+1);
}

Re: perf_counters issue with enable_on_exec

[stephane eranian]

On Mon, Aug 24, 2009 at 3:46 PM, Peter Zijlstra<a.p.zijlstra@chello.nl> wrote:
> On Thu, 2009-08-20 at 15:49 +0200, stephane eranian wrote:
>> Hi,
>>
>> I am running into an issue trying to use enable_on_exec
>> in per-thread mode with an event group.
>>
>> My understanding is that enable_on_exec allows activation
>> of an event on first exec. This is useful for tools monitoring
>> other tasks and which you invoke as: tool my_program. In
>> other words, the tool forks+execs my_program. This option
>> allows developers to setup the events after the fork (to get
>> the pid) but before the exec(). Only execution after the exec
>> is monitored. This alleviates the need to use the
>> ptrace(PTRACE_TRACEME) call.
>>
>> My understanding is that an event group is scheduled only
>> if all events in the group are active (disabled=0). Thus, one
>> trick to activate a group  with a single ioctl(PERF_IOC_ENABLE)
>> is to enable all events in the group except the leader. This works
>> well. But once you add enable_on_exec on on the events,
>> things go wrong. The non-leader events start counting before
>> the exec. If the non-leader events are created in disabled state,
>> then they never activate on exec.
>>
>> The attached test program demonstrates the problem.
>> simply invoke with a program that runs for a few seconds.
>
> OK, lots of issues here
>
>  1) your code is broken ;-)

That's true. I knew about the missing synchro. But I think
the problem existed nonetheless.

>  2) enable_on_exec on !leader counters is undefined

then fail it.

>  3) there is something fishy non the less
>
True.

>
> 1. you fork() then create a counter group in both the parent and the
> child without sync, then read the parent group. This obviously doesn't
> do what is expected. See attached proglet for a better version.
>
I have modified the program based on your changes. See new version attached.

> 2. enable_on_exec only works on leaders, Paul, was that intended?
>
All events in a group are scheduled together. If one event is not enabled
in a group, then the group is not dispatched. Setting enable_on_exec
just on leader makes sense. Then to enable the group on exec, you
enabled all events but the leader. The enable_on_exec will enable
the leader on exec and the group will be ready for dispatch. That's
how it should work in my mind.


As you indicated the issue is with the timing information and I think
it is not related to enable_on_exec. It is more related to the fact
that to enable a group with a single ioctl() you enable ALL BUT the
leader. But that means that the time_enabled for the !leader is
ticking. Thus scaling won't be as expected yet it is correct
given what happens internally.

I think there needs to be a distinction between 'enabled immediately
but cannot run because group is not totally enabled' and 'cannot run
because the group has been multiplexed out yet all could be dispatched
because all events were dispatched'. In the former, it seems you don't
want time_enabled to tick, while in the latter you do. In other words,
time_enabled ticks for each event if the group is 'dispatch-able' (or
runnable in your terminology) otherwise it does not. time_enabled reflects
the fact that the group could run but did not have access to the PMU
resource because of contention with other groups.


> # ./test-enable_on_exec true
>             2651600 PERF_COUNT_HW_CPU_CYCLES 1111509 1111509 2651600.000000
>             1832720 PERF_COUNT_HW_INSTRUCTIONS 839395242 1111509 1384043177.264637
>
> Paul, would a counter's time start running when its 'enabled' but part
> of a non-runnable group?
>
>
#include <sys/types.h>
#include <inttypes.h>
#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>
#include <unistd.h>
#include <string.h>
#include <sys/wait.h>
#include <syscall.h>
#include <err.h>

#include <perfmon/pfmlib_perf_counter.h>


int
child(char **arg)
{
        int i;

        /* burn cycles to detect if monitoring start before exec */
        for(i=0; i < 5000000; i++) syscall(__NR_getpid);
        /*
         * execute the requested command
         */
        execvp(arg[0], arg);
        errx(1, "cannot exec: %s\n", arg[0]);
        /* not reached */
}

int
parent(char **arg)
{
        struct perf_counter_attr hw[2];
        char *name[2], buf;
        int fd[2];
        int status, ret, i;
        uint64_t values[3];
        pid_t pid;
        int ready[2], go[2];


        ret = pipe(ready);
        if (ret)
                err(1, "cannot create pipe ready");

        ret = pipe(go);
        if (ret)
                err(1, "cannot create pipe go");

        /*
         * Create the child task
         */
        if ((pid=fork()) == -1)
                err(1, "Cannot fork process");

        /*
         * and launch the child code
         */
        if (pid == 0) {
                close(ready[0]);
                close(go[1]);

                /*
                 * let the parent know we exist
                 */
               close(ready[1]);
               if (read(go[0], &buf, 1) == -1)
                       err(1, "unable to read go_pipe");

                close(go[0]);
                exit(child(arg));
        }

        close(ready[1]);
        close(go[0]);

        if (read(ready[0], &buf, 1) == -1)
               err(1, "unable to read child_ready_pipe");

        close(ready[0]);

        memset(hw, 0, sizeof(hw));

        name[0] = "PERF_COUNT_HW_CPU_CYCLES";
        hw[0].type = PERF_TYPE_HARDWARE;
        hw[0].config = PERF_COUNT_HW_CPU_CYCLES;
        hw[0].read_format =
PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
        hw[0].disabled = 1;
        hw[0].enable_on_exec = 1;

        name[1] = "PERF_COUNT_HW_CPU_CYCLES";
        hw[1].type = PERF_TYPE_HARDWARE;
        hw[1].config = PERF_COUNT_HW_CPU_CYCLES;
        hw[1].read_format =
PERF_FORMAT_TOTAL_TIME_ENABLED|PERF_FORMAT_TOTAL_TIME_RUNNING;
        hw[1].disabled = 0;
        hw[1].enable_on_exec = 0;

        fd[0] = perf_counter_open(&hw[0], pid, -1, -1, 0);
        if (fd[0] == -1)
                err(1, "cannot open event0");

        fd[1] = perf_counter_open(&hw[1], pid, -1, fd[0], 0);
        if (fd[1] == -1)
                err(1, "cannot open event1");


        close(go[1]);

        waitpid(pid, &status, 0);

        /*
         * the task has disappeared at this point but our session is still
         * present and contains all the latest counts.
         */

        /*
         * now simply read the results.
         */
        for(i=0; i < 2; i++) {
                ret = read(fd[i], values, sizeof(values));
                if (ret < sizeof(values))
                        err(1, "cannot read values event %s", name[i]);

                printf("%20"PRIu64" %s %ld %ld %f\n",
                        values[0],
                        name[i],
                        values[1], values[2],
                        values[2] ? (double)values[0] *
values[1]/values[2] : 0);

                close(fd[i]);
        }
        return 0;
}

int
main(int argc, char **argv)
{
        if (!argv[1])
                errx(1, "you must specify a command to execute\n");

        return parent(argv+1);
}

Re: perf_counters issue with enable_on_exec

[stephane eranian]

On Mon, Aug 24, 2009 at 5:44 PM, stephane eranian<eranian@googlemail.com> wrote:
> On Mon, Aug 24, 2009 at 3:46 PM, Peter Zijlstra<a.p.zijlstra@chello.nl> wrote:
>> On Thu, 2009-08-20 at 15:49 +0200, stephane eranian wrote:
>>> Hi,
>>>
>>> I am running into an issue trying to use enable_on_exec
>>> in per-thread mode with an event group.
>>>
>>> My understanding is that enable_on_exec allows activation
>>> of an event on first exec. This is useful for tools monitoring
>>> other tasks and which you invoke as: tool my_program. In
>>> other words, the tool forks+execs my_program. This option
>>> allows developers to setup the events after the fork (to get
>>> the pid) but before the exec(). Only execution after the exec
>>> is monitored. This alleviates the need to use the
>>> ptrace(PTRACE_TRACEME) call.
>>>
>>> My understanding is that an event group is scheduled only
>>> if all events in the group are active (disabled=0). Thus, one
>>> trick to activate a group  with a single ioctl(PERF_IOC_ENABLE)
>>> is to enable all events in the group except the leader. This works
>>> well. But once you add enable_on_exec on on the events,
>>> things go wrong. The non-leader events start counting before
>>> the exec. If the non-leader events are created in disabled state,
>>> then they never activate on exec.
>>>
>>> The attached test program demonstrates the problem.
>>> simply invoke with a program that runs for a few seconds.
>>
>> OK, lots of issues here
>>
>>  1) your code is broken ;-)
>
> That's true. I knew about the missing synchro. But I think
> the problem existed nonetheless.
>
>>  2) enable_on_exec on !leader counters is undefined
>
> then fail it.
>
>>  3) there is something fishy non the less
>>
> True.
>
>>
>> 1. you fork() then create a counter group in both the parent and the
>> child without sync, then read the parent group. This obviously doesn't
>> do what is expected. See attached proglet for a better version.
>>
> I have modified the program based on your changes. See new version attached.
>
>> 2. enable_on_exec only works on leaders, Paul, was that intended?
>>
> All events in a group are scheduled together. If one event is not enabled
> in a group, then the group is not dispatched. Setting enable_on_exec
> just on leader makes sense. Then to enable the group on exec, you
> enabled all events but the leader. The enable_on_exec will enable
> the leader on exec and the group will be ready for dispatch. That's
> how it should work in my mind.
>
>
> As you indicated the issue is with the timing information and I think
> it is not related to enable_on_exec. It is more related to the fact
> that to enable a group with a single ioctl() you enable ALL BUT the
> leader. But that means that the time_enabled for the !leader is
> ticking. Thus scaling won't be as expected yet it is correct
> given what happens internally.
>
> I think there needs to be a distinction between 'enabled immediately
> but cannot run because group is not totally enabled' and 'cannot run
> because the group has been multiplexed out yet all could be dispatched
> because all events were dispatched'. In the former, it seems you don't
> want time_enabled to tick, while in the latter you do. In other words,
> time_enabled ticks for each event if the group is 'dispatch-able' (or
> runnable in your terminology) otherwise it does not. time_enabled reflects
> the fact that the group could run but did not have access to the PMU
> resource because of contention with other groups.
>
In other words, I think timing_enabled is measuring the wrong thing.
It should be instead called time_runnable and it should measure the
time during which the event is runnable, i.e, its group is runnable. That
means the event (group) could be dispatched if PMU was "free".

Re: perf_counters issue with enable_on_exec

[Peter Zijlstra]

On Mon, 2009-08-24 at 18:03 +0200, stephane eranian wrote:

> >>  2) enable_on_exec on !leader counters is undefined
> >
> > then fail it.

Or make it work :-)

> >>  3) there is something fishy non the less
> >>
> > True.
> >
> >>
> >> 1. you fork() then create a counter group in both the parent and the
> >> child without sync, then read the parent group. This obviously doesn't
> >> do what is expected. See attached proglet for a better version.
> >>
> > I have modified the program based on your changes. See new version attached.
> >
> >> 2. enable_on_exec only works on leaders, Paul, was that intended?
> >>
> > All events in a group are scheduled together. If one event is not enabled
> > in a group, then the group is not dispatched. Setting enable_on_exec
> > just on leader makes sense. Then to enable the group on exec, you
> > enabled all events but the leader. The enable_on_exec will enable
> > the leader on exec and the group will be ready for dispatch. That's
> > how it should work in my mind.
> >
> >
> > As you indicated the issue is with the timing information and I think
> > it is not related to enable_on_exec. It is more related to the fact
> > that to enable a group with a single ioctl() you enable ALL BUT the
> > leader. But that means that the time_enabled for the !leader is
> > ticking. Thus scaling won't be as expected yet it is correct
> > given what happens internally.
> >
> > I think there needs to be a distinction between 'enabled immediately
> > but cannot run because group is not totally enabled' and 'cannot run
> > because the group has been multiplexed out yet all could be dispatched
> > because all events were dispatched'. In the former, it seems you don't
> > want time_enabled to tick, while in the latter you do. In other words,
> > time_enabled ticks for each event if the group is 'dispatch-able' (or
> > runnable in your terminology) otherwise it does not. time_enabled reflects
> > the fact that the group could run but did not have access to the PMU
> > resource because of contention with other groups.
> >
> In other words, I think timing_enabled is measuring the wrong thing.
> It should be instead called time_runnable and it should measure the
> time during which the event is runnable, i.e, its group is runnable. That
> means the event (group) could be dispatched if PMU was "free".

I tend to agree with you, but I'm hoping Paul will speak since he wrote
both the time accounting and the enable_on_exec thing.

Re: perf_counters issue with enable_on_exec

[stephane eranian]

On Mon, Aug 24, 2009 at 6:06 PM, Peter Zijlstra<a.p.zijlstra@chello.nl> wrote:
> On Mon, 2009-08-24 at 18:03 +0200, stephane eranian wrote:
>
>> >>  2) enable_on_exec on !leader counters is undefined
>> >
>> > then fail it.
>
> Or make it work :-)
>
But what would that mean given how a group is made runnable?

>> In other words, I think timing_enabled is measuring the wrong thing.
>> It should be instead called time_runnable and it should measure the
>> time during which the event is runnable, i.e, its group is runnable. That
>> means the event (group) could be dispatched if PMU was "free".
>
> I tend to agree with you, but I'm hoping Paul will speak since he wrote
> both the time accounting and the enable_on_exec thing.
>
Fair enough.

Re: perf_counters issue with enable_on_exec

[Paul Mackerras]

stephane eranian writes:

> I am running into an issue trying to use enable_on_exec
> in per-thread mode with an event group.
> 
> My understanding is that enable_on_exec allows activation
> of an event on first exec. This is useful for tools monitoring
> other tasks and which you invoke as: tool my_program. In
> other words, the tool forks+execs my_program. This option
> allows developers to setup the events after the fork (to get
> the pid) but before the exec(). Only execution after the exec
> is monitored. This alleviates the need to use the
> ptrace(PTRACE_TRACEME) call.
> 
> My understanding is that an event group is scheduled only
> if all events in the group are active (disabled=0). Thus, one

Not quite - if the leader is disabled then none of the group goes on.
If the leader is enabled then it and any other group members that are
enabled go on.  If a non-leader member is disabled then it doesn't go
on but it doesn't stop other members from going on.

Paul.

Re: perf_counters issue with enable_on_exec

[Paul Mackerras]

Peter Zijlstra writes:

> 2. enable_on_exec only works on leaders, Paul, was that intended?

I think I thought that would be sufficient, but I guess it would be
cleaner if it also worked on non-leaders.

> 3. the scale stuff seems broken
> 
> # perf stat -e cycles -e instructions --repeat 10 true
> 
>  Performance counter stats for 'true' (10 runs):
> 
>         2612124  cycles                     ( +-   1.327% )
>         1870479  instructions             #      0.716 IPC     ( +-   0.132% )
> 
>     0.003743155  seconds time elapsed   ( +-   1.203% )
> 
> # ./test-enable_on_exec true
>              2651600 PERF_COUNT_HW_CPU_CYCLES 1111509 1111509 2651600.000000
>              1832720 PERF_COUNT_HW_INSTRUCTIONS 839395242 1111509 1384043177.264637
> 
> Paul, would a counter's time start running when its 'enabled' but part
> of a non-runnable group?

No, it shouldn't.  If it does it's a bug.

Paul.

Re: perf_counters issue with enable_on_exec

[stephane eranian]

On Mon, Aug 24, 2009 at 11:35 PM, Paul Mackerras<paulus@samba.org> wrote:
> stephane eranian writes:
>
>> I am running into an issue trying to use enable_on_exec
>> in per-thread mode with an event group.
>>
>> My understanding is that enable_on_exec allows activation
>> of an event on first exec. This is useful for tools monitoring
>> other tasks and which you invoke as: tool my_program. In
>> other words, the tool forks+execs my_program. This option
>> allows developers to setup the events after the fork (to get
>> the pid) but before the exec(). Only execution after the exec
>> is monitored. This alleviates the need to use the
>> ptrace(PTRACE_TRACEME) call.
>>
>> My understanding is that an event group is scheduled only
>> if all events in the group are active (disabled=0). Thus, one
>
> Not quite - if the leader is disabled then none of the group goes on.
> If the leader is enabled then it and any other group members that are
> enabled go on.  If a non-leader member is disabled then it doesn't go
> on but it doesn't stop other members from going on.
>
okay, what is not clear to me is why you need that level of granularity?

Re: perf_counters issue with enable_on_exec

[Paul Mackerras]

stephane eranian writes:

> As you indicated the issue is with the timing information and I think
> it is not related to enable_on_exec. It is more related to the fact
> that to enable a group with a single ioctl() you enable ALL BUT the
> leader. But that means that the time_enabled for the !leader is
> ticking. Thus scaling won't be as expected yet it is correct
> given what happens internally.

No, time_enabled shouldn't be increasing for a counter that's in a
group whose leader is disabled.

I'll try out your test program today.

> I think there needs to be a distinction between 'enabled immediately
> but cannot run because group is not totally enabled' and 'cannot run
> because the group has been multiplexed out yet all could be dispatched
> because all events were dispatched'. In the former, it seems you don't
> want time_enabled to tick, while in the latter you do. In other words,
> time_enabled ticks for each event if the group is 'dispatch-able' (or
> runnable in your terminology) otherwise it does not. time_enabled reflects
> the fact that the group could run but did not have access to the PMU
> resource because of contention with other groups.

Right.  That is exactly what the code is supposed to do.  If it
doesn't there's a bug.

Paul.

[PATCH] perf_counter: Start counting time enabled when group leader gets enabled

[Paul Mackerras]

Currently, if a group is created where the group leader is initially
disabled but a non-leader member is initially enabled, and then the
leader is subsequently enabled some time later, the time_enabled for
the non-leader member will reflect the whole time since it was created,
not just the time since the leader was enabled.  This is incorrect,
because all of the members are effectively disabled while the leader
is disabled, since none of the members can go on the PMU if the leader
can't.

Thus we have to update the ->tstamp_enabled for all the enabled group
members when a group leader is enabled, so that the time_enabled
computation only counts the time since the leader was enabled.
Similarly, when disabling a group leader we have to update the
time_enabled and time_running for all of the group members.
Also, in update_counter_times, we have to treat a counter whose group
leader is disabled as being disabled.

Reported-by: Stephane Eranian <eranian@googlemail.com>
Signed-off-by: Paul Mackerras <paulus@samba.org>
---
Stephane, this should fix the problem you were seeing.  Let me know
whether it does or not.

 kernel/perf_counter.c |   43 ++++++++++++++++++++++++++++++-------------
 1 files changed, 30 insertions(+), 13 deletions(-)

diff --git a/kernel/perf_counter.c b/kernel/perf_counter.c
index f274e19..06bf6a4 100644
--- a/kernel/perf_counter.c
+++ b/kernel/perf_counter.c
@@ -469,7 +469,8 @@ static void update_counter_times(struct perf_counter *counter)
 	struct perf_counter_context *ctx = counter->ctx;
 	u64 run_end;
 
-	if (counter->state < PERF_COUNTER_STATE_INACTIVE)
+	if (counter->state < PERF_COUNTER_STATE_INACTIVE ||
+	    counter->group_leader->state < PERF_COUNTER_STATE_INACTIVE)
 		return;
 
 	counter->total_time_enabled = ctx->time - counter->tstamp_enabled;
@@ -518,7 +519,7 @@ static void __perf_counter_disable(void *info)
 	 */
 	if (counter->state >= PERF_COUNTER_STATE_INACTIVE) {
 		update_context_time(ctx);
-		update_counter_times(counter);
+		update_group_times(counter);
 		if (counter == counter->group_leader)
 			group_sched_out(counter, cpuctx, ctx);
 		else
@@ -573,7 +574,7 @@ static void perf_counter_disable(struct perf_counter *counter)
 	 * in, so we can change the state safely.
 	 */
 	if (counter->state == PERF_COUNTER_STATE_INACTIVE) {
-		update_counter_times(counter);
+		update_group_times(counter);
 		counter->state = PERF_COUNTER_STATE_OFF;
 	}
 
@@ -851,6 +852,27 @@ retry:
 }
 
 /*
+ * Put a counter into inactive state and update time fields.
+ * Enabling the leader of a group effectively enables all
+ * the group members that aren't explicitly disabled, so we
+ * have to update their ->tstamp_enabled also.
+ * Note: this works for group members as well as group leaders
+ * since the non-leader members' sibling_lists will be empty.
+ */
+static void __perf_counter_mark_enabled(struct perf_counter *counter,
+					struct perf_counter_context *ctx)
+{
+	struct perf_counter *sub;
+
+	counter->state = PERF_COUNTER_STATE_INACTIVE;
+	counter->tstamp_enabled = ctx->time - counter->total_time_enabled;
+	list_for_each_entry(sub, &counter->sibling_list, list_entry)
+		if (sub->state >= PERF_COUNTER_STATE_INACTIVE)
+			sub->tstamp_enabled =
+				ctx->time - sub->total_time_enabled;
+}
+
+/*
  * Cross CPU call to enable a performance counter
  */
 static void __perf_counter_enable(void *info)
@@ -877,8 +899,7 @@ static void __perf_counter_enable(void *info)
 
 	if (counter->state >= PERF_COUNTER_STATE_INACTIVE)
 		goto unlock;
-	counter->state = PERF_COUNTER_STATE_INACTIVE;
-	counter->tstamp_enabled = ctx->time - counter->total_time_enabled;
+	__perf_counter_mark_enabled(counter, ctx);
 
 	/*
 	 * If the counter is in a group and isn't the group leader,
@@ -971,11 +992,9 @@ static void perf_counter_enable(struct perf_counter *counter)
 	 * Since we have the lock this context can't be scheduled
 	 * in, so we can change the state safely.
 	 */
-	if (counter->state == PERF_COUNTER_STATE_OFF) {
-		counter->state = PERF_COUNTER_STATE_INACTIVE;
-		counter->tstamp_enabled =
-			ctx->time - counter->total_time_enabled;
-	}
+	if (counter->state == PERF_COUNTER_STATE_OFF)
+		__perf_counter_mark_enabled(counter, ctx);
+
  out:
 	spin_unlock_irq(&ctx->lock);
 }
@@ -1479,9 +1498,7 @@ static void perf_counter_enable_on_exec(struct task_struct *task)
 		counter->attr.enable_on_exec = 0;
 		if (counter->state >= PERF_COUNTER_STATE_INACTIVE)
 			continue;
-		counter->state = PERF_COUNTER_STATE_INACTIVE;
-		counter->tstamp_enabled =
-			ctx->time - counter->total_time_enabled;
+		__perf_counter_mark_enabled(counter, ctx);
 		enabled = 1;
 	}
 
-- 
1.5.5.rc3.7.gba13

Re: [PATCH] perf_counter: Start counting time enabled when group leader gets enabled

[Peter Zijlstra]

On Tue, 2009-08-25 at 15:17 +1000, Paul Mackerras wrote:
> Currently, if a group is created where the group leader is initially
> disabled but a non-leader member is initially enabled, and then the
> leader is subsequently enabled some time later, the time_enabled for
> the non-leader member will reflect the whole time since it was created,
> not just the time since the leader was enabled.  This is incorrect,
> because all of the members are effectively disabled while the leader
> is disabled, since none of the members can go on the PMU if the leader
> can't.
> 
> Thus we have to update the ->tstamp_enabled for all the enabled group
> members when a group leader is enabled, so that the time_enabled
> computation only counts the time since the leader was enabled.
> Similarly, when disabling a group leader we have to update the
> time_enabled and time_running for all of the group members.
> Also, in update_counter_times, we have to treat a counter whose group
> leader is disabled as being disabled.
> 
> Reported-by: Stephane Eranian <eranian@googlemail.com>
> Signed-off-by: Paul Mackerras <paulus@samba.org>

Looks good, thanks Paul!

[tip:perfcounters/core] perf_counter: Start counting time enabled when group leader gets enabled

[tip-bot for Paul Mackerras]

Commit-ID:  fa289beca9de9119c7760bd984f3640da21bc94c
Gitweb:     http://git.kernel.org/tip/fa289beca9de9119c7760bd984f3640da21bc94c
Author:     Paul Mackerras <paulus@samba.org>
AuthorDate: Tue, 25 Aug 2009 15:17:20 +1000
Committer:  Ingo Molnar <mingo@elte.hu>
CommitDate: Tue, 25 Aug 2009 09:34:38 +0200

perf_counter: Start counting time enabled when group leader gets enabled

Currently, if a group is created where the group leader is
initially disabled but a non-leader member is initially
enabled, and then the leader is subsequently enabled some time
later, the time_enabled for the non-leader member will reflect
the whole time since it was created, not just the time since
the leader was enabled.

This is incorrect, because all of the members are effectively
disabled while the leader is disabled, since none of the
members can go on the PMU if the leader can't.

Thus we have to update the ->tstamp_enabled for all the enabled
group members when a group leader is enabled, so that the
time_enabled computation only counts the time since the leader
was enabled.

Similarly, when disabling a group leader we have to update the
time_enabled and time_running for all of the group members.

Also, in update_counter_times, we have to treat a counter whose
group leader is disabled as being disabled.

Reported-by: Stephane Eranian <eranian@googlemail.com>
Signed-off-by: Paul Mackerras <paulus@samba.org>
Acked-by: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: <stable@kernel.org>
LKML-Reference: <19091.29664.342227.445006@drongo.ozlabs.ibm.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>


---
 kernel/perf_counter.c |   43 ++++++++++++++++++++++++++++++-------------
 1 files changed, 30 insertions(+), 13 deletions(-)

diff --git a/kernel/perf_counter.c b/kernel/perf_counter.c
index f274e19..06bf6a4 100644
--- a/kernel/perf_counter.c
+++ b/kernel/perf_counter.c
@@ -469,7 +469,8 @@ static void update_counter_times(struct perf_counter *counter)
 	struct perf_counter_context *ctx = counter->ctx;
 	u64 run_end;
 
-	if (counter->state < PERF_COUNTER_STATE_INACTIVE)
+	if (counter->state < PERF_COUNTER_STATE_INACTIVE ||
+	    counter->group_leader->state < PERF_COUNTER_STATE_INACTIVE)
 		return;
 
 	counter->total_time_enabled = ctx->time - counter->tstamp_enabled;
@@ -518,7 +519,7 @@ static void __perf_counter_disable(void *info)
 	 */
 	if (counter->state >= PERF_COUNTER_STATE_INACTIVE) {
 		update_context_time(ctx);
-		update_counter_times(counter);
+		update_group_times(counter);
 		if (counter == counter->group_leader)
 			group_sched_out(counter, cpuctx, ctx);
 		else
@@ -573,7 +574,7 @@ static void perf_counter_disable(struct perf_counter *counter)
 	 * in, so we can change the state safely.
 	 */
 	if (counter->state == PERF_COUNTER_STATE_INACTIVE) {
-		update_counter_times(counter);
+		update_group_times(counter);
 		counter->state = PERF_COUNTER_STATE_OFF;
 	}
 
@@ -851,6 +852,27 @@ retry:
 }
 
 /*
+ * Put a counter into inactive state and update time fields.
+ * Enabling the leader of a group effectively enables all
+ * the group members that aren't explicitly disabled, so we
+ * have to update their ->tstamp_enabled also.
+ * Note: this works for group members as well as group leaders
+ * since the non-leader members' sibling_lists will be empty.
+ */
+static void __perf_counter_mark_enabled(struct perf_counter *counter,
+					struct perf_counter_context *ctx)
+{
+	struct perf_counter *sub;
+
+	counter->state = PERF_COUNTER_STATE_INACTIVE;
+	counter->tstamp_enabled = ctx->time - counter->total_time_enabled;
+	list_for_each_entry(sub, &counter->sibling_list, list_entry)
+		if (sub->state >= PERF_COUNTER_STATE_INACTIVE)
+			sub->tstamp_enabled =
+				ctx->time - sub->total_time_enabled;
+}
+
+/*
  * Cross CPU call to enable a performance counter
  */
 static void __perf_counter_enable(void *info)
@@ -877,8 +899,7 @@ static void __perf_counter_enable(void *info)
 
 	if (counter->state >= PERF_COUNTER_STATE_INACTIVE)
 		goto unlock;
-	counter->state = PERF_COUNTER_STATE_INACTIVE;
-	counter->tstamp_enabled = ctx->time - counter->total_time_enabled;
+	__perf_counter_mark_enabled(counter, ctx);
 
 	/*
 	 * If the counter is in a group and isn't the group leader,
@@ -971,11 +992,9 @@ static void perf_counter_enable(struct perf_counter *counter)
 	 * Since we have the lock this context can't be scheduled
 	 * in, so we can change the state safely.
 	 */
-	if (counter->state == PERF_COUNTER_STATE_OFF) {
-		counter->state = PERF_COUNTER_STATE_INACTIVE;
-		counter->tstamp_enabled =
-			ctx->time - counter->total_time_enabled;
-	}
+	if (counter->state == PERF_COUNTER_STATE_OFF)
+		__perf_counter_mark_enabled(counter, ctx);
+
  out:
 	spin_unlock_irq(&ctx->lock);
 }
@@ -1479,9 +1498,7 @@ static void perf_counter_enable_on_exec(struct task_struct *task)
 		counter->attr.enable_on_exec = 0;
 		if (counter->state >= PERF_COUNTER_STATE_INACTIVE)
 			continue;
-		counter->state = PERF_COUNTER_STATE_INACTIVE;
-		counter->tstamp_enabled =
-			ctx->time - counter->total_time_enabled;
+		__perf_counter_mark_enabled(counter, ctx);
 		enabled = 1;
 	}