kvmarm.lists.cs.columbia.edu archive mirror
 help / color / mirror / Atom feed
From: Eric Auger <eric.auger@redhat.com>
To: Alexandru Elisei <alexandru.elisei@arm.com>
Cc: eric.auger.pro@gmail.com, kvm@vger.kernel.org,
	kvmarm@lists.linux.dev, andrew.jones@linux.dev, maz@kernel.org,
	will@kernel.org, oliver.upton@linux.dev, ricarkol@google.com,
	reijiw@google.com
Subject: Re: [kvm-unit-tests PATCH 1/6] arm: pmu: pmu-chain-promotion: Improve debug messages
Date: Mon, 24 Apr 2023 22:09:14 +0200	[thread overview]
Message-ID: <745cd61a-4dbd-4e1b-630c-2f21eec7b005@redhat.com> (raw)
In-Reply-To: <ZEJWhPtA2xaaqV54@monolith.localdoman>

Hi Alexandru,

On 4/21/23 11:25, Alexandru Elisei wrote:
> Hi,
>
> On Wed, Mar 15, 2023 at 12:07:20PM +0100, Eric Auger wrote:
>> The pmu-chain-promotion test is composed of several subtests.
>> In case of failures, the current logs are really dificult to
>> analyze since they look very similar and sometimes duplicated
>> for each subtest. Add prefixes for each subtest and introduce
>> a macro that prints the registers we are mostly interested in,
>> namerly the 2 first counters and the overflow counter.
> One possible typo below.
renamed 2d into 2nd as suggested.
>
> Ran pmu-chain-promotion with and without this patch applied, the
> improvement is very noticeable, it makes it very easy to match the debug
> message with the subtest being run:
>
> Reviewed-by: Alexandru Elisei <alexandru.elisei@arm.com>

Thanks!

Eric
>
>> Signed-off-by: Eric Auger <eric.auger@redhat.com>
>> ---
>>  arm/pmu.c | 63 ++++++++++++++++++++++++++++---------------------------
>>  1 file changed, 32 insertions(+), 31 deletions(-)
>>
>> diff --git a/arm/pmu.c b/arm/pmu.c
>> index f6e95012..dad7d4b4 100644
>> --- a/arm/pmu.c
>> +++ b/arm/pmu.c
>> @@ -715,6 +715,11 @@ static void test_chained_sw_incr(bool unused)
>>  	report_info("overflow=0x%lx, #0=0x%lx #1=0x%lx", read_sysreg(pmovsclr_el0),
>>  		    read_regn_el0(pmevcntr, 0), read_regn_el0(pmevcntr, 1));
>>  }
>> +#define PRINT_REGS(__s) \
>> +	report_info("%s #1=0x%lx #0=0x%lx overflow=0x%lx", __s, \
>> +		    read_regn_el0(pmevcntr, 1), \
>> +		    read_regn_el0(pmevcntr, 0), \
>> +		    read_sysreg(pmovsclr_el0))
>>  
>>  static void test_chain_promotion(bool unused)
>>  {
>> @@ -725,6 +730,7 @@ static void test_chain_promotion(bool unused)
>>  		return;
>>  
>>  	/* Only enable CHAIN counter */
>> +	report_prefix_push("subtest1");
>>  	pmu_reset();
>>  	write_regn_el0(pmevtyper, 0, MEM_ACCESS | PMEVTYPER_EXCLUDE_EL0);
>>  	write_regn_el0(pmevtyper, 1, CHAIN | PMEVTYPER_EXCLUDE_EL0);
>> @@ -732,83 +738,81 @@ static void test_chain_promotion(bool unused)
>>  	isb();
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> +	PRINT_REGS("post");
>>  	report(!read_regn_el0(pmevcntr, 0),
>>  		"chain counter not counting if even counter is disabled");
>> +	report_prefix_pop();
>>  
>>  	/* Only enable even counter */
>> +	report_prefix_push("subtest2");
>>  	pmu_reset();
>>  	write_regn_el0(pmevcntr, 0, PRE_OVERFLOW_32);
>>  	write_sysreg_s(0x1, PMCNTENSET_EL0);
>>  	isb();
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> +	PRINT_REGS("post");
>>  	report(!read_regn_el0(pmevcntr, 1) && (read_sysreg(pmovsclr_el0) == 0x1),
>>  		"odd counter did not increment on overflow if disabled");
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> -	report_info("CHAIN counter #1 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 1));
>> -	report_info("overflow counter 0x%lx", read_sysreg(pmovsclr_el0));
>> +	report_prefix_pop();
>>  
>>  	/* start at 0xFFFFFFDC, +20 with CHAIN enabled, +20 with CHAIN disabled */
>> +	report_prefix_push("subtest3");
>>  	pmu_reset();
>>  	write_sysreg_s(0x3, PMCNTENSET_EL0);
>>  	write_regn_el0(pmevcntr, 0, PRE_OVERFLOW2_32);
>>  	isb();
>> +	PRINT_REGS("init");
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +	PRINT_REGS("After 1st loop");
>>  
>>  	/* disable the CHAIN event */
>>  	write_sysreg_s(0x2, PMCNTENCLR_EL0);
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +	PRINT_REGS("After 2d loop");
> Hmm.. was that supposed to be "after 2**n**d loop" (matches the "after 1st
> loop" message)? A few more instances below.
>
> Thanks,
> Alex
>
>>  	report(read_sysreg(pmovsclr_el0) == 0x1,
>>  		"should have triggered an overflow on #0");
>>  	report(!read_regn_el0(pmevcntr, 1),
>>  		"CHAIN counter #1 shouldn't have incremented");
>> +	report_prefix_pop();
>>  
>>  	/* start at 0xFFFFFFDC, +20 with CHAIN disabled, +20 with CHAIN enabled */
>>  
>> +	report_prefix_push("subtest4");
>>  	pmu_reset();
>>  	write_sysreg_s(0x1, PMCNTENSET_EL0);
>>  	write_regn_el0(pmevcntr, 0, PRE_OVERFLOW2_32);
>>  	isb();
>> -	report_info("counter #0 = 0x%lx, counter #1 = 0x%lx overflow=0x%lx",
>> -		    read_regn_el0(pmevcntr, 0), read_regn_el0(pmevcntr, 1),
>> -		    read_sysreg(pmovsclr_el0));
>> +	PRINT_REGS("init");
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +	PRINT_REGS("After 1st loop");
>>  
>>  	/* enable the CHAIN event */
>>  	write_sysreg_s(0x3, PMCNTENSET_EL0);
>>  	isb();
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +
>> +	PRINT_REGS("After 2d loop");
>>  
>>  	report((read_regn_el0(pmevcntr, 1) == 1) &&
>>  		(read_sysreg(pmovsclr_el0) == 0x1),
>>  		"CHAIN counter enabled: CHAIN counter was incremented and overflow");
>> -
>> -	report_info("CHAIN counter #1 = 0x%lx, overflow=0x%lx",
>> -		read_regn_el0(pmevcntr, 1), read_sysreg(pmovsclr_el0));
>> +	report_prefix_pop();
>>  
>>  	/* start as MEM_ACCESS/CPU_CYCLES and move to CHAIN/MEM_ACCESS */
>> +	report_prefix_push("subtest5");
>>  	pmu_reset();
>>  	write_regn_el0(pmevtyper, 0, MEM_ACCESS | PMEVTYPER_EXCLUDE_EL0);
>>  	write_regn_el0(pmevtyper, 1, CPU_CYCLES | PMEVTYPER_EXCLUDE_EL0);
>>  	write_sysreg_s(0x3, PMCNTENSET_EL0);
>>  	write_regn_el0(pmevcntr, 0, PRE_OVERFLOW2_32);
>>  	isb();
>> +	PRINT_REGS("init");
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +	PRINT_REGS("After 1st loop");
>>  
>>  	/* 0 becomes CHAINED */
>>  	write_sysreg_s(0x0, PMCNTENSET_EL0);
>> @@ -817,37 +821,34 @@ static void test_chain_promotion(bool unused)
>>  	write_regn_el0(pmevcntr, 1, 0x0);
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("MEM_ACCESS counter #0 has value 0x%lx",
>> -		    read_regn_el0(pmevcntr, 0));
>> +	PRINT_REGS("After 2d loop");
>>  
>>  	report((read_regn_el0(pmevcntr, 1) == 1) &&
>>  		(read_sysreg(pmovsclr_el0) == 0x1),
>>  		"32b->64b: CHAIN counter incremented and overflow");
>> -
>> -	report_info("CHAIN counter #1 = 0x%lx, overflow=0x%lx",
>> -		read_regn_el0(pmevcntr, 1), read_sysreg(pmovsclr_el0));
>> +	report_prefix_pop();
>>  
>>  	/* start as CHAIN/MEM_ACCESS and move to MEM_ACCESS/CPU_CYCLES */
>> +	report_prefix_push("subtest6");
>>  	pmu_reset();
>>  	write_regn_el0(pmevtyper, 0, MEM_ACCESS | PMEVTYPER_EXCLUDE_EL0);
>>  	write_regn_el0(pmevtyper, 1, CHAIN | PMEVTYPER_EXCLUDE_EL0);
>>  	write_regn_el0(pmevcntr, 0, PRE_OVERFLOW2_32);
>>  	write_sysreg_s(0x3, PMCNTENSET_EL0);
>> +	PRINT_REGS("init");
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> -	report_info("counter #0=0x%lx, counter #1=0x%lx",
>> -			read_regn_el0(pmevcntr, 0), read_regn_el0(pmevcntr, 1));
>> +	PRINT_REGS("After 1st loop");
>>  
>>  	write_sysreg_s(0x0, PMCNTENSET_EL0);
>>  	write_regn_el0(pmevtyper, 1, CPU_CYCLES | PMEVTYPER_EXCLUDE_EL0);
>>  	write_sysreg_s(0x3, PMCNTENSET_EL0);
>>  
>>  	mem_access_loop(addr, 20, pmu.pmcr_ro | PMU_PMCR_E);
>> +	PRINT_REGS("After 2d loop");
>>  	report(read_sysreg(pmovsclr_el0) == 1,
>>  		"overflow is expected on counter 0");
>> -	report_info("counter #0=0x%lx, counter #1=0x%lx overflow=0x%lx",
>> -			read_regn_el0(pmevcntr, 0), read_regn_el0(pmevcntr, 1),
>> -			read_sysreg(pmovsclr_el0));
>> +	report_prefix_pop();
>>  }
>>  
>>  static bool expect_interrupts(uint32_t bitmap)
>> -- 
>> 2.38.1
>>


  reply	other threads:[~2023-04-24 20:09 UTC|newest]

Thread overview: 28+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2023-03-15 11:07 [kvm-unit-tests PATCH 0/6] arm: pmu: Fix random failures of pmu-chain-promotion Eric Auger
2023-03-15 11:07 ` [kvm-unit-tests PATCH 1/6] arm: pmu: pmu-chain-promotion: Improve debug messages Eric Auger
2023-04-21  9:25   ` Alexandru Elisei
2023-04-24 20:09     ` Eric Auger [this message]
2023-03-15 11:07 ` [kvm-unit-tests PATCH 2/6] arm: pmu: pmu-chain-promotion: Introduce defines for count and margin values Eric Auger
2023-04-21  9:55   ` Alexandru Elisei
2023-04-24 20:09     ` Eric Auger
2023-03-15 11:07 ` [kvm-unit-tests PATCH 3/6] arm: pmu: Add extra DSB barriers in the mem_access loop Eric Auger
2023-04-21 10:25   ` Alexandru Elisei
2023-04-24 20:11     ` Eric Auger
2023-04-25 13:00       ` Alexandru Elisei
2023-05-31 20:14         ` Eric Auger
2023-03-15 11:07 ` [kvm-unit-tests PATCH 4/6] arm: pmu: Fix chain counter enable/disable sequences Eric Auger
2023-04-21 10:52   ` Alexandru Elisei
2023-04-21 11:24     ` Marc Zyngier
2023-05-31 20:15     ` Eric Auger
2023-03-15 11:07 ` [kvm-unit-tests PATCH 5/6] arm: pmu: Add pmu-memaccess-reliability test Eric Auger
2023-04-21 11:13   ` Alexandru Elisei
2023-05-31 20:15     ` Eric Auger
2023-03-15 11:07 ` [kvm-unit-tests PATCH 6/6] arm: pmu-chain-promotion: Increase the count and margin values Eric Auger
2023-04-04  6:23 ` [kvm-unit-tests PATCH 0/6] arm: pmu: Fix random failures of pmu-chain-promotion Eric Auger
2023-04-04 12:47   ` Andrew Jones
2023-04-12  7:34     ` Andrew Jones
2023-04-12  8:55       ` Alexandru Elisei
2023-04-12  8:47     ` Mark Rutland
2023-04-19  7:32       ` Eric Auger
2023-04-19  9:39         ` Alexandru Elisei
2023-04-21  8:11           ` Eric Auger

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=745cd61a-4dbd-4e1b-630c-2f21eec7b005@redhat.com \
    --to=eric.auger@redhat.com \
    --cc=alexandru.elisei@arm.com \
    --cc=andrew.jones@linux.dev \
    --cc=eric.auger.pro@gmail.com \
    --cc=kvm@vger.kernel.org \
    --cc=kvmarm@lists.linux.dev \
    --cc=maz@kernel.org \
    --cc=oliver.upton@linux.dev \
    --cc=reijiw@google.com \
    --cc=ricarkol@google.com \
    --cc=will@kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body. 
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).