Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <630ab636-107d-4b12-5454-2ee91ad43543@arm.com>
Date:   Tue, 30 May 2023 15:28:09 +0100
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101
 Thunderbird/102.9.0
Subject: Re: [PATCH 2/4] perf cs-etm: Use previous thread for branch sample
 source IP
Content-Language: en-US
To:     Leo Yan <leo.yan@linaro.org>
Cc:     coresight@lists.linaro.org, denik@chromium.org,
        Suzuki K Poulose <suzuki.poulose@arm.com>,
        Mike Leach <mike.leach@linaro.org>,
        Peter Zijlstra <peterz@infradead.org>,
        Ingo Molnar <mingo@redhat.com>,
        Arnaldo Carvalho de Melo <acme@kernel.org>,
        Mark Rutland <mark.rutland@arm.com>,
        Alexander Shishkin <alexander.shishkin@linux.intel.com>,
        Jiri Olsa <jolsa@kernel.org>,
        Namhyung Kim <namhyung@kernel.org>,
        Ian Rogers <irogers@google.com>,
        Adrian Hunter <adrian.hunter@intel.com>,
        John Garry <john.g.garry@oracle.com>,
        Will Deacon <will@kernel.org>,
        linux-arm-kernel@lists.infradead.org,
        linux-perf-users@vger.kernel.org, linux-kernel@vger.kernel.org
References: <20230524131958.2139331-1-james.clark@arm.com>
 <20230524131958.2139331-3-james.clark@arm.com>
 <20230527090635.GB886420@leoy-yangtze.lan>
From:   James Clark <james.clark@arm.com>
In-Reply-To: <20230527090635.GB886420@leoy-yangtze.lan>
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit
Precedence: bulk


On 27/05/2023 10:06, Leo Yan wrote:
> On Wed, May 24, 2023 at 02:19:56PM +0100, James Clark wrote:
>> Branch samples currently use the IP of the previous packet as the from
>> IP, and the IP of the current packet as the to IP. But it incorrectly
>> uses the current thread. In some cases like a jump into a different
>> exception level this will attribute to the incorrect process.
> 
> It's about the timing that branch has taken or not taken :)
> 
> If we think the branch sample as 'branch has taken', then current code
> is doning right thing, otherwise, we need this fix.
> 

If you diff the outputs side by side you can see it mainly has an effect
where there is a discontinuity. At this point we set either the from or
the to IPs to 0.

For example here is a before and after perf script output. Without the
change it looks like stress was running before it actually was. The
schedule function that was attributed to ls on the first line hasn't
finished running yet. But it's attributed to stress on the second line
even though the destination IP is 0 meaning we don't even know where it
went.

Before:

    ls  8350 [006] ... __schedule+0x394 => schedule+0x5c
stress  8357 [006] ... schedule+0x84 => 0 [unknown]
stress  8357 [006] ... 0 [unknown] => __unix_dgram_recvmsg+0x130

After:

    ls  8350 [006] ... __schedule+0x394 => schedule+0x5c
    ls  8357 [006] ... schedule+0x84 => 0 [unknown]
stress  8357 [006] ... 0 [unknown] => __unix_dgram_recvmsg+0x130

I didn't see any decode differences that weren't around these
discontinuity points, so it seems like a low risk change.

>> Fix it by tracking the previous thread in the same way the previous
>> packet is tracked.
>>
>> Signed-off-by: James Clark <james.clark@arm.com>
>> ---
>>  tools/perf/util/cs-etm.c | 9 +++++++--
>>  1 file changed, 7 insertions(+), 2 deletions(-)
>>
>> diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c
>> index ebffc9052561..a997fe79d458 100644
>> --- a/tools/perf/util/cs-etm.c
>> +++ b/tools/perf/util/cs-etm.c
>> @@ -86,6 +86,7 @@ struct cs_etm_traceid_queue {
>>  	size_t last_branch_pos;
>>  	union perf_event *event_buf;
>>  	struct thread *thread;
>> +	struct thread *prev_thread;
>>  	struct branch_stack *last_branch;
>>  	struct branch_stack *last_branch_rb;
>>  	struct cs_etm_packet *prev_packet;
>> @@ -480,6 +481,7 @@ static int cs_etm__init_traceid_queue(struct cs_etm_queue *etmq,
>>  	tidq->trace_chan_id = trace_chan_id;
>>  	tidq->thread = machine__findnew_thread(&etm->session->machines.host, -1,
>>  					       queue->tid);
>> +	tidq->prev_thread = machine__idle_thread(&etm->session->machines.host);
>>  
>>  	tidq->packet = zalloc(sizeof(struct cs_etm_packet));
>>  	if (!tidq->packet)
>> @@ -616,6 +618,8 @@ static void cs_etm__packet_swap(struct cs_etm_auxtrace *etm,
>>  		tmp = tidq->packet;
>>  		tidq->packet = tidq->prev_packet;
>>  		tidq->prev_packet = tmp;
>> +		thread__put(tidq->prev_thread);
>> +		tidq->prev_thread = thread__get(tidq->thread);
> 
> Maybe cs_etm__packet_swap() is not the best place to update
> "tidq->prev_thread", since swapping packet doesn't mean it's necessarily
> thread switching; can we move this change into the cs_etm__set_thread()?
> 

Yeah that might make more sense. I can move it there if we decide to
keep this change.

> Thanks,
> Leo
> 
>>  	}
>>  }
>>  
>> @@ -791,6 +795,7 @@ static void cs_etm__free_traceid_queues(struct cs_etm_queue *etmq)
>>  		/* Free this traceid_queue from the array */
>>  		tidq = etmq->traceid_queues[idx];
>>  		thread__zput(tidq->thread);
>> +		thread__zput(tidq->prev_thread);
>>  		zfree(&tidq->event_buf);
>>  		zfree(&tidq->last_branch);
>>  		zfree(&tidq->last_branch_rb);
>> @@ -1450,8 +1455,8 @@ static int cs_etm__synth_branch_sample(struct cs_etm_queue *etmq,
>>  	sample.time = cs_etm__resolve_sample_time(etmq, tidq);
>>  
>>  	sample.ip = ip;
>> -	sample.pid = tidq->thread->pid_;
>> -	sample.tid = tidq->thread->tid;
>> +	sample.pid = tidq->prev_thread->pid_;
>> +	sample.tid = tidq->prev_thread->tid;
>>  	sample.addr = cs_etm__first_executed_instr(tidq->packet);
>>  	sample.id = etmq->etm->branches_id;
>>  	sample.stream_id = etmq->etm->branches_id;
>> -- 
>> 2.34.1
>>