From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-8.3 required=3.0 tests=DKIM_SIGNED,DKIM_VALID, DKIM_VALID_AU,HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_PATCH,MAILING_LIST_MULTI, SIGNED_OFF_BY,SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED,USER_AGENT_SANE_1 autolearn=ham autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id DDA49C47404 for ; Fri, 11 Oct 2019 20:17:55 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id A9CA12084C for ; Fri, 11 Oct 2019 20:17:55 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (2048-bit key) header.d=linaro.org header.i=@linaro.org header.b="AXmpi7ke" Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1729330AbfJKURy (ORCPT ); Fri, 11 Oct 2019 16:17:54 -0400 Received: from mail-pg1-f195.google.com ([209.85.215.195]:42113 "EHLO mail-pg1-f195.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1729106AbfJKURy (ORCPT ); Fri, 11 Oct 2019 16:17:54 -0400 Received: by mail-pg1-f195.google.com with SMTP id f14so1291610pgi.9 for ; Fri, 11 Oct 2019 13:17:53 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=date:from:to:cc:subject:message-id:references:mime-version :content-disposition:in-reply-to:user-agent; bh=urKtgcUqAkGp8KZBc5+oZtHTmWIcz82tEFRNTfuvdn4=; b=AXmpi7kejzX23jX+27pOe3agKp/6or0QiTrtZTRQk8imHTwVDIPlt7zAlpLwHTDmuM WcAdOnI30lpOnV/urS4PpjaIT4siN4pVPGVW9CMRtzjT1g1A2gepjSRffqI+FCRphsWm dZSPAUK+NPEgFsvkDPV2yCTh8mAFw/G++hRzIU/bu5REGQW9JRIS3mp/dELwY5++Q8tb oMPdMuFGBhDhl6LtGzArcMzLzVIJpfeYHiCONqiYz1jXhquUFROPQpLtkSikFAuax+50 SF6uPoFyJ5awRs+H+rCfPJ3wysh4NOF5TO7VVo7LwYT8ALPeMEuijne7GVDpmPOluO7L pm+Q== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:subject:message-id:references :mime-version:content-disposition:in-reply-to:user-agent; bh=urKtgcUqAkGp8KZBc5+oZtHTmWIcz82tEFRNTfuvdn4=; b=ZMhOH0Zt0AABGevDbyS5T2pqjiGlo/JT7G2PdocAs0w8OtmJ2KNJGrnOnQiDx6Jhzq JgjdK2AA4RddyiPWiv1abuMeNR3J/0w+PYStff78gwILlR7NwHzBWE221GglFOKi9gUV AmeEBLB0qT/8TQ/XoDBu6ZZdEGM8+FVMz5I9zv2VNO6NmSapS6tN2H1h31Ko78RCMxyZ azobRsfYwMDgPrz6kEVeWgg/LnuhJmUQj2lpcj6cRybNC8QvDOkhVJwJH/Od+ZT1TwNV 5E2tou6LtONxFTSyk5GR+yc48rD1AxVDbIc1kVUyTUvcryr9bVk/5+teXzRtbY90GX/r /Prw== X-Gm-Message-State: APjAAAXHeGj8oeINvcumawbk0CB4zJzShPTcHVsse8Vx/DY1Pidzn/Gl yzCk7p2Ng0hXwyloorE5fbIMBA== X-Google-Smtp-Source: APXvYqy38uKd8VmnBen9hFXQxvk0j0GYq4h83Htd1vNyCXJhBgpeD8RsBQrvhqjAymF9cy+J3yvh8g== X-Received: by 2002:a17:90a:9306:: with SMTP id p6mr19281294pjo.68.1570825073251; Fri, 11 Oct 2019 13:17:53 -0700 (PDT) Received: from xps15 (S0106002369de4dac.cg.shawcable.net. [68.147.8.254]) by smtp.gmail.com with ESMTPSA id z13sm11344787pfg.172.2019.10.11.13.17.52 (version=TLS1_2 cipher=ECDHE-RSA-CHACHA20-POLY1305 bits=256/256); Fri, 11 Oct 2019 13:17:52 -0700 (PDT) Date: Fri, 11 Oct 2019 14:17:50 -0600 From: Mathieu Poirier To: Leo Yan Cc: Arnaldo Carvalho de Melo , Suzuki K Poulose , Mark Rutland , Alexander Shishkin , Jiri Olsa , Namhyung Kim , linux-arm-kernel@lists.infradead.org, linux-kernel@vger.kernel.org, Mike Leach , Coresight ML , Peter Zijlstra , Ingo Molnar Subject: Re: [PATCH v3 6/6] perf cs-etm: Synchronize instruction sample with the thread stack Message-ID: <20191011201750.GD13688@xps15> References: <20191005091614.11635-1-leo.yan@linaro.org> <20191005091614.11635-7-leo.yan@linaro.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20191005091614.11635-7-leo.yan@linaro.org> User-Agent: Mutt/1.9.4 (2018-02-28) Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Sat, Oct 05, 2019 at 05:16:14PM +0800, Leo Yan wrote: > The synthesized flow use 'tidq->packet' for instruction samples; on the > other hand, 'tidp->prev_packet' is used to generate the thread stack and > the branch samples, this results in the instruction samples using one > packet ahead than thread stack and branch samples ('tidp->prev_packet' > vs 'tidq->packet'). > > This leads to an instruction's callchain error as shows in below > example: > > main 1579 100 instructions: > ffff000010214854 perf_event_update_userpage+0x4c ([kernel.kallsyms]) > ffff000010214850 perf_event_update_userpage+0x48 ([kernel.kallsyms]) > ffff000010219360 perf_swevent_add+0x88 ([kernel.kallsyms]) > ffff0000102135f4 event_sched_in.isra.57+0xbc ([kernel.kallsyms]) > ffff0000102137a0 group_sched_in+0x60 ([kernel.kallsyms]) > ffff000010213b84 flexible_sched_in+0xfc ([kernel.kallsyms]) > ffff00001020c0b4 visit_groups_merge+0x12c ([kernel.kallsyms]) > > In the callchain log, for the two continuous lines the up line contains > one child function info and the followed line contains the caller > function info, and so forth. So the first two lines are: > > perf_event_update_userpage+0x4c => the sampled instruction > perf_event_update_userpage+0x48 => the parent function's calling > > The child function and parent function both are the same function > perf_event_update_userpage(), but this isn't a recursive function, thus > the sequence for perf_event_update_userpage() calling itself shouldn't > never happen. This callchain error is caused by the instruction sample > using an ahead packet than the thread stack, the thread stack is deferred > to process the new packet and misses to pop stack if it is just a return > packet. > > To fix this issue, we can simply change to use 'tidq->prev_packet' to > generate the instruction samples, this allows the thread stack to push > and pop synchronously with instruction sample. Finally, the callchain > can be displayed correctly as below: > > main 1579 100 instructions: > ffff000010214854 perf_event_update_userpage+0x4c ([kernel.kallsyms]) > ffff000010219360 perf_swevent_add+0x88 ([kernel.kallsyms]) > ffff0000102135f4 event_sched_in.isra.57+0xbc ([kernel.kallsyms]) > ffff0000102137a0 group_sched_in+0x60 ([kernel.kallsyms]) > ffff000010213b84 flexible_sched_in+0xfc ([kernel.kallsyms]) > ffff00001020c0b4 visit_groups_merge+0x12c ([kernel.kallsyms]) > > Signed-off-by: Leo Yan > --- > tools/perf/util/cs-etm.c | 4 ++-- > 1 file changed, 2 insertions(+), 2 deletions(-) > > diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c > index 56e501cd2f5f..fa969dcb45d2 100644 > --- a/tools/perf/util/cs-etm.c > +++ b/tools/perf/util/cs-etm.c > @@ -1419,7 +1419,7 @@ static int cs_etm__sample(struct cs_etm_queue *etmq, > struct cs_etm_packet *tmp; > int ret; > u8 trace_chan_id = tidq->trace_chan_id; > - u64 instrs_executed = tidq->packet->instr_count; > + u64 instrs_executed = tidq->prev_packet->instr_count; > > tidq->period_instructions += instrs_executed; > > @@ -1450,7 +1450,7 @@ static int cs_etm__sample(struct cs_etm_queue *etmq, > */ > s64 offset = (instrs_executed - instrs_over - 1); > u64 addr = cs_etm__instr_addr(etmq, trace_chan_id, > - tidq->packet, offset); > + tidq->prev_packet, offset); I have tested this set in --per-thread mode and things are working as advertised. Did you see how things look like in CPU-wide scenarios? Thanks, Mathieu > > ret = cs_etm__synth_instruction_sample( > etmq, tidq, addr, etm->instructions_sample_period); > -- > 2.17.1 > From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-8.3 required=3.0 tests=DKIMWL_WL_HIGH,DKIM_SIGNED, DKIM_VALID,HEADER_FROM_DIFFERENT_DOMAINS,INCLUDES_PATCH,MAILING_LIST_MULTI, SIGNED_OFF_BY,SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED,USER_AGENT_SANE_1 autolearn=unavailable autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 98DDDC47404 for ; Fri, 11 Oct 2019 20:18:06 +0000 (UTC) Received: from bombadil.infradead.org (bombadil.infradead.org [198.137.202.133]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPS id 65A2D21835 for ; Fri, 11 Oct 2019 20:18:06 +0000 (UTC) Authentication-Results: mail.kernel.org; dkim=pass (2048-bit key) header.d=lists.infradead.org header.i=@lists.infradead.org header.b="Ti9xARBd"; dkim=fail reason="signature verification failed" (2048-bit key) header.d=linaro.org header.i=@linaro.org header.b="AXmpi7ke" DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 65A2D21835 Authentication-Results: mail.kernel.org; dmarc=fail (p=none dis=none) header.from=linaro.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=linux-arm-kernel-bounces+infradead-linux-arm-kernel=archiver.kernel.org@lists.infradead.org DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=lists.infradead.org; s=bombadil.20170209; h=Sender: Content-Transfer-Encoding:Content-Type:Cc:List-Subscribe:List-Help:List-Post: List-Archive:List-Unsubscribe:List-Id:In-Reply-To:MIME-Version:References: Message-ID:Subject:To:From:Date:Reply-To:Content-ID:Content-Description: Resent-Date:Resent-From:Resent-Sender:Resent-To:Resent-Cc:Resent-Message-ID: List-Owner; bh=xm8UM6fj1nk0SLCIybYZvXDFpyU3yB7xgLwzK3u8Ai4=; b=Ti9xARBdqSmabr l+9ZwC7ikFiuTVPlzoAc8jIUV1khao0svOjXtZSdSE6+oFyOnw3MaaY31NBRiI56Gclj/xl4eVWM/ 3ZmWblFlsgR3Z/xn5sH7Lz6RbSGdlAhmlItPYTczmYB34YNcELdtiivqxyJnkMiPx0QKkD9wSkjK7 g9mxHojMVlFQLO6FgnznjA9356fhzQ0f/D6SWUZ8Tjk0gxHjsWwruPmMQUNbTPZYVSXzjmx9w8ES+ 0QyKkzAbasmjOQdAaBVEJTM1sXbycIF1RF43byJBPfjOxz5WrZPCuMf1QpIQtrQwMQMgNgon+Z6iT Bwx2VShGaBuChTNCuGeQ==; Received: from localhost ([127.0.0.1] helo=bombadil.infradead.org) by bombadil.infradead.org with esmtp (Exim 4.92.3 #3 (Red Hat Linux)) id 1iJ1MM-0000QR-GX; Fri, 11 Oct 2019 20:17:58 +0000 Received: from mail-pg1-x543.google.com ([2607:f8b0:4864:20::543]) by bombadil.infradead.org with esmtps (Exim 4.92.3 #3 (Red Hat Linux)) id 1iJ1MI-0000PH-8g for linux-arm-kernel@lists.infradead.org; Fri, 11 Oct 2019 20:17:56 +0000 Received: by mail-pg1-x543.google.com with SMTP id f14so1291611pgi.9 for ; Fri, 11 Oct 2019 13:17:53 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=date:from:to:cc:subject:message-id:references:mime-version :content-disposition:in-reply-to:user-agent; bh=urKtgcUqAkGp8KZBc5+oZtHTmWIcz82tEFRNTfuvdn4=; b=AXmpi7kejzX23jX+27pOe3agKp/6or0QiTrtZTRQk8imHTwVDIPlt7zAlpLwHTDmuM WcAdOnI30lpOnV/urS4PpjaIT4siN4pVPGVW9CMRtzjT1g1A2gepjSRffqI+FCRphsWm dZSPAUK+NPEgFsvkDPV2yCTh8mAFw/G++hRzIU/bu5REGQW9JRIS3mp/dELwY5++Q8tb oMPdMuFGBhDhl6LtGzArcMzLzVIJpfeYHiCONqiYz1jXhquUFROPQpLtkSikFAuax+50 SF6uPoFyJ5awRs+H+rCfPJ3wysh4NOF5TO7VVo7LwYT8ALPeMEuijne7GVDpmPOluO7L pm+Q== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:date:from:to:cc:subject:message-id:references :mime-version:content-disposition:in-reply-to:user-agent; bh=urKtgcUqAkGp8KZBc5+oZtHTmWIcz82tEFRNTfuvdn4=; b=KLcWbMXbaPG8TQciPy8+7dL6s5BWR3YRQVs9HLV1gBR6y4TVszJU6VfScDqW1nbApS +Urc1ZNB5+HsRD4J00yCIWzf1ROkMN8ufzKkr8FJUO0lBO32dAyA+hNUCEVv+HC/bZMV Ywnjki94CJ4bKksl9UMqiHbw+BSKAT2EEa5h0Xo7gDxA7rIWIS0Cxjhm393Z/Ai6eXvq 7h08R9JztYtItuArw3TlqLASq9bji1h94oxSPjgZhlD8Yw/1EV68tIKY5xigVIg0gko+ vTD5CV3zuOLMNf+c5U0pQF5NHcMRAp0fPPRaRDACJOPXy4gwJiS9vzhvkSkWBT1Nd3+4 6AcQ== X-Gm-Message-State: APjAAAVRoOKhbV65df5W8e1+i22sQZw/3RoOcDq0A1yznabWtfEixAPJ +TrYkS4n3xwdma74yh4b7GiCXw== X-Google-Smtp-Source: APXvYqy38uKd8VmnBen9hFXQxvk0j0GYq4h83Htd1vNyCXJhBgpeD8RsBQrvhqjAymF9cy+J3yvh8g== X-Received: by 2002:a17:90a:9306:: with SMTP id p6mr19281294pjo.68.1570825073251; Fri, 11 Oct 2019 13:17:53 -0700 (PDT) Received: from xps15 (S0106002369de4dac.cg.shawcable.net. [68.147.8.254]) by smtp.gmail.com with ESMTPSA id z13sm11344787pfg.172.2019.10.11.13.17.52 (version=TLS1_2 cipher=ECDHE-RSA-CHACHA20-POLY1305 bits=256/256); Fri, 11 Oct 2019 13:17:52 -0700 (PDT) Date: Fri, 11 Oct 2019 14:17:50 -0600 From: Mathieu Poirier To: Leo Yan Subject: Re: [PATCH v3 6/6] perf cs-etm: Synchronize instruction sample with the thread stack Message-ID: <20191011201750.GD13688@xps15> References: <20191005091614.11635-1-leo.yan@linaro.org> <20191005091614.11635-7-leo.yan@linaro.org> MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: <20191005091614.11635-7-leo.yan@linaro.org> User-Agent: Mutt/1.9.4 (2018-02-28) X-CRM114-Version: 20100106-BlameMichelson ( TRE 0.8.0 (BSD) ) MR-646709E3 X-CRM114-CacheID: sfid-20191011_131754_311098_A375E3A0 X-CRM114-Status: GOOD ( 22.35 ) X-BeenThere: linux-arm-kernel@lists.infradead.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: Mark Rutland , Suzuki K Poulose , Alexander Shishkin , Coresight ML , linux-kernel@vger.kernel.org, Arnaldo Carvalho de Melo , Peter Zijlstra , Ingo Molnar , Namhyung Kim , Jiri Olsa , linux-arm-kernel@lists.infradead.org, Mike Leach Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Sender: "linux-arm-kernel" Errors-To: linux-arm-kernel-bounces+infradead-linux-arm-kernel=archiver.kernel.org@lists.infradead.org On Sat, Oct 05, 2019 at 05:16:14PM +0800, Leo Yan wrote: > The synthesized flow use 'tidq->packet' for instruction samples; on the > other hand, 'tidp->prev_packet' is used to generate the thread stack and > the branch samples, this results in the instruction samples using one > packet ahead than thread stack and branch samples ('tidp->prev_packet' > vs 'tidq->packet'). > > This leads to an instruction's callchain error as shows in below > example: > > main 1579 100 instructions: > ffff000010214854 perf_event_update_userpage+0x4c ([kernel.kallsyms]) > ffff000010214850 perf_event_update_userpage+0x48 ([kernel.kallsyms]) > ffff000010219360 perf_swevent_add+0x88 ([kernel.kallsyms]) > ffff0000102135f4 event_sched_in.isra.57+0xbc ([kernel.kallsyms]) > ffff0000102137a0 group_sched_in+0x60 ([kernel.kallsyms]) > ffff000010213b84 flexible_sched_in+0xfc ([kernel.kallsyms]) > ffff00001020c0b4 visit_groups_merge+0x12c ([kernel.kallsyms]) > > In the callchain log, for the two continuous lines the up line contains > one child function info and the followed line contains the caller > function info, and so forth. So the first two lines are: > > perf_event_update_userpage+0x4c => the sampled instruction > perf_event_update_userpage+0x48 => the parent function's calling > > The child function and parent function both are the same function > perf_event_update_userpage(), but this isn't a recursive function, thus > the sequence for perf_event_update_userpage() calling itself shouldn't > never happen. This callchain error is caused by the instruction sample > using an ahead packet than the thread stack, the thread stack is deferred > to process the new packet and misses to pop stack if it is just a return > packet. > > To fix this issue, we can simply change to use 'tidq->prev_packet' to > generate the instruction samples, this allows the thread stack to push > and pop synchronously with instruction sample. Finally, the callchain > can be displayed correctly as below: > > main 1579 100 instructions: > ffff000010214854 perf_event_update_userpage+0x4c ([kernel.kallsyms]) > ffff000010219360 perf_swevent_add+0x88 ([kernel.kallsyms]) > ffff0000102135f4 event_sched_in.isra.57+0xbc ([kernel.kallsyms]) > ffff0000102137a0 group_sched_in+0x60 ([kernel.kallsyms]) > ffff000010213b84 flexible_sched_in+0xfc ([kernel.kallsyms]) > ffff00001020c0b4 visit_groups_merge+0x12c ([kernel.kallsyms]) > > Signed-off-by: Leo Yan > --- > tools/perf/util/cs-etm.c | 4 ++-- > 1 file changed, 2 insertions(+), 2 deletions(-) > > diff --git a/tools/perf/util/cs-etm.c b/tools/perf/util/cs-etm.c > index 56e501cd2f5f..fa969dcb45d2 100644 > --- a/tools/perf/util/cs-etm.c > +++ b/tools/perf/util/cs-etm.c > @@ -1419,7 +1419,7 @@ static int cs_etm__sample(struct cs_etm_queue *etmq, > struct cs_etm_packet *tmp; > int ret; > u8 trace_chan_id = tidq->trace_chan_id; > - u64 instrs_executed = tidq->packet->instr_count; > + u64 instrs_executed = tidq->prev_packet->instr_count; > > tidq->period_instructions += instrs_executed; > > @@ -1450,7 +1450,7 @@ static int cs_etm__sample(struct cs_etm_queue *etmq, > */ > s64 offset = (instrs_executed - instrs_over - 1); > u64 addr = cs_etm__instr_addr(etmq, trace_chan_id, > - tidq->packet, offset); > + tidq->prev_packet, offset); I have tested this set in --per-thread mode and things are working as advertised. Did you see how things look like in CPU-wide scenarios? Thanks, Mathieu > > ret = cs_etm__synth_instruction_sample( > etmq, tidq, addr, etm->instructions_sample_period); > -- > 2.17.1 > _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel