KVM Archive on lore.kernel.org
 help / color / Atom feed
* [kvm-unit-tests PATCH] arm: expand the timer tests
@ 2020-01-10 16:05 Alex Bennée
  2020-01-13 13:48 ` Alexandru Elisei
  0 siblings, 1 reply; 4+ messages in thread
From: Alex Bennée @ 2020-01-10 16:05 UTC (permalink / raw)
  To: pbonzini
  Cc: kvm, linux-arm-kernel, kvmarm, christoffer.dall, maz, Alex Bennée

This was an attempt to replicate a QEMU bug. However to trigger the
bug you need to have an offset set in EL2 which kvm-unit-tests is
unable to do. However it does exercise some more corner cases.

Bug: https://bugs.launchpad.net/bugs/1859021
Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 arm/timer.c | 27 ++++++++++++++++++++++++++-
 1 file changed, 26 insertions(+), 1 deletion(-)

diff --git a/arm/timer.c b/arm/timer.c
index f390e8e..ae1d299 100644
--- a/arm/timer.c
+++ b/arm/timer.c
@@ -214,21 +214,46 @@ static void test_timer(struct timer_info *info)
 	 * still read the pending state even if it's disabled. */
 	set_timer_irq_enabled(info, false);
 
+	/* Verify count goes up */
+	report(info->read_counter() >= now, "counter increments");
+
 	/* Enable the timer, but schedule it for much later */
 	info->write_cval(later);
 	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
 	isb();
-	report(!gic_timer_pending(info), "not pending before");
+	report(!gic_timer_pending(info), "not pending before 10s");
+
+	/* Check with a maximum possible cval */
+	info->write_cval(UINT64_MAX);
+	isb();
+	report(!gic_timer_pending(info), "not pending before UINT64_MAX");
+
+	/* also by setting tval */
+	info->write_tval(time_10s);
+	isb();
+	report(!gic_timer_pending(info), "not pending before 10s (via tval)");
+	report_info("TVAL is %d (delta CVAL %ld) ticks",
+		    info->read_tval(), info->read_cval() - info->read_counter());
 
+        /* check pending once cval is before now */
 	info->write_cval(now - 1);
 	isb();
 	report(gic_timer_pending(info), "interrupt signal pending");
+	report_info("TVAL is %d ticks", info->read_tval());
 
 	/* Disable the timer again and prepare to take interrupts */
 	info->write_ctl(0);
 	set_timer_irq_enabled(info, true);
 	report(!gic_timer_pending(info), "interrupt signal no longer pending");
 
+	/* QEMU bug when cntvoff_el2 > 0
+	 * https://bugs.launchpad.net/bugs/1859021 */
+	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
+	info->write_cval(UINT64_MAX);
+	isb();
+	report(!gic_timer_pending(info), "not pending before UINT64_MAX (irqs on)");
+	info->write_ctl(0);
+
 	report(test_cval_10msec(info), "latency within 10 ms");
 	report(info->irq_received, "interrupt received");
 
-- 
2.20.1


^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [kvm-unit-tests PATCH] arm: expand the timer tests
  2020-01-10 16:05 [kvm-unit-tests PATCH] arm: expand the timer tests Alex Bennée
@ 2020-01-13 13:48 ` Alexandru Elisei
  2020-01-13 14:07   ` Alexandru Elisei
  2020-01-13 17:38   ` Alex Bennée
  0 siblings, 2 replies; 4+ messages in thread
From: Alexandru Elisei @ 2020-01-13 13:48 UTC (permalink / raw)
  To: Alex Bennée, pbonzini; +Cc: kvm, maz, kvmarm, linux-arm-kernel

Hi,

On 1/10/20 4:05 PM, Alex Bennée wrote:
> This was an attempt to replicate a QEMU bug. However to trigger the
> bug you need to have an offset set in EL2 which kvm-unit-tests is
> unable to do. However it does exercise some more corner cases.
>
> Bug: https://bugs.launchpad.net/bugs/1859021

I'm not aware of any Bug: tags in the Linux kernel. If you want people to follow
the link to the bug, how about referencing something like this:

"This was an attempt to replicate a QEMU bug [1]. [..]

[1] https://bugs.launchpad.net/qemu/+bug/1859021"

Also, are launchpad bug reports permanent? Will the link still work in a years' time?

> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> ---
>  arm/timer.c | 27 ++++++++++++++++++++++++++-
>  1 file changed, 26 insertions(+), 1 deletion(-)
>
> diff --git a/arm/timer.c b/arm/timer.c
> index f390e8e..ae1d299 100644
> --- a/arm/timer.c
> +++ b/arm/timer.c
> @@ -214,21 +214,46 @@ static void test_timer(struct timer_info *info)
>  	 * still read the pending state even if it's disabled. */
>  	set_timer_irq_enabled(info, false);
>  
> +	/* Verify count goes up */
> +	report(info->read_counter() >= now, "counter increments");
> +
>  	/* Enable the timer, but schedule it for much later */
>  	info->write_cval(later);
>  	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
>  	isb();
> -	report(!gic_timer_pending(info), "not pending before");
> +	report(!gic_timer_pending(info), "not pending before 10s");
> +
> +	/* Check with a maximum possible cval */
> +	info->write_cval(UINT64_MAX);
> +	isb();
> +	report(!gic_timer_pending(info), "not pending before UINT64_MAX");
> +
> +	/* also by setting tval */

All the comments in this file seem to start with a capital letter.

> +	info->write_tval(time_10s);
> +	isb();
> +	report(!gic_timer_pending(info), "not pending before 10s (via tval)");

You can remove the "(via tval)" part - the message is unique enough to figure out
which part of the test it refers to.

> +	report_info("TVAL is %d (delta CVAL %ld) ticks",
> +		    info->read_tval(), info->read_cval() - info->read_counter());

I'm not sure what you are trying to achieve with this. You can transform it to
check that TVAL is indeed positive and (almost) equal to cval - cntpct, something
like this:

+	s32 tval = info->read_tval();
+	report(tval > 0 && tval <= info->read_cval() - info->read_counter(), "TVAL measures time to next interrupt");

>  
> +        /* check pending once cval is before now */

This comment adds nothing to the test.

>  	info->write_cval(now - 1);
>  	isb();
>  	report(gic_timer_pending(info), "interrupt signal pending");
> +	report_info("TVAL is %d ticks", info->read_tval());

You can test that TVAL is negative here instead of printing the value.

>  
>  	/* Disable the timer again and prepare to take interrupts */
>  	info->write_ctl(0);
>  	set_timer_irq_enabled(info, true);
>  	report(!gic_timer_pending(info), "interrupt signal no longer pending");
>  
> +	/* QEMU bug when cntvoff_el2 > 0
> +	 * https://bugs.launchpad.net/bugs/1859021 */

This looks confusing to me. From the commit message, I got that kvm-unit-tests
needs qemu to set a special value for CNTVOFF_EL2. But the comments seems to
suggest that kvm-unit-tests can trigger the bug without qemu doing anything
special. Can you elaborate under which condition kvm-unit-tests can trigger the bug?

> +	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
> +	info->write_cval(UINT64_MAX);

The order is wrong - you write CVAL first, *then* enable to timer. Otherwise you
might get an interrupt because of the previous CVAL value.

The previous value for CVAL was now -1, so your change triggers an unwanted
interrupt after enabling the timer. The interrupt handler masks the timer
interrupt at the timer level, which means that as far as the gic is concerned the
interrupt is not pending, making the report call afterwards useless.

> +	isb();
> +	report(!gic_timer_pending(info), "not pending before UINT64_MAX (irqs on)");

This check can be improved. You want to check the timer CTL.ISTATUS here, not the
gic. A device (in this case, the timer) can assert the interrupt, but the gic does
not sample it immediately. Come to think of it, the entire timer test is wrong
because of this.

Thanks,
Alex
> +	info->write_ctl(0);
> +
>  	report(test_cval_10msec(info), "latency within 10 ms");
>  	report(info->irq_received, "interrupt received");
>  

^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [kvm-unit-tests PATCH] arm: expand the timer tests
  2020-01-13 13:48 ` Alexandru Elisei
@ 2020-01-13 14:07   ` Alexandru Elisei
  2020-01-13 17:38   ` Alex Bennée
  1 sibling, 0 replies; 4+ messages in thread
From: Alexandru Elisei @ 2020-01-13 14:07 UTC (permalink / raw)
  To: Alex Bennée, pbonzini; +Cc: kvm, maz, kvmarm, linux-arm-kernel

On 1/13/20 1:48 PM, Alexandru Elisei wrote:
> [..]
>> +	isb();
>> +	report(!gic_timer_pending(info), "not pending before UINT64_MAX (irqs on)");
> This check can be improved. You want to check the timer CTL.ISTATUS here, not the
> gic. A device (in this case, the timer) can assert the interrupt, but the gic does
> not sample it immediately. Come to think of it, the entire timer test is wrong
> because of this.

I'll write a patch for it in v4 of my fixes series.

Thanks,
Alex



^ permalink raw reply	[flat|nested] 4+ messages in thread

* Re: [kvm-unit-tests PATCH] arm: expand the timer tests
  2020-01-13 13:48 ` Alexandru Elisei
  2020-01-13 14:07   ` Alexandru Elisei
@ 2020-01-13 17:38   ` Alex Bennée
  1 sibling, 0 replies; 4+ messages in thread
From: Alex Bennée @ 2020-01-13 17:38 UTC (permalink / raw)
  To: Alexandru Elisei; +Cc: kvm, maz, kvmarm, linux-arm-kernel


Alexandru Elisei <alexandru.elisei@arm.com> writes:

> Hi,
>
> On 1/10/20 4:05 PM, Alex Bennée wrote:
>> This was an attempt to replicate a QEMU bug. However to trigger the
>> bug you need to have an offset set in EL2 which kvm-unit-tests is
>> unable to do. However it does exercise some more corner cases.
>>
>> Bug: https://bugs.launchpad.net/bugs/1859021
>
> I'm not aware of any Bug: tags in the Linux kernel. If you want people to follow
> the link to the bug, how about referencing something like this:
>
> "This was an attempt to replicate a QEMU bug [1]. [..]
>
> [1] https://bugs.launchpad.net/qemu/+bug/1859021"

OK, I'll fix that in v2.

>
> Also, are launchpad bug reports permanent? Will the link still work in
> a years' time?

They should be - they are a unique id and we use them in the QEMU source
tree.

>
>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
>> ---
>>  arm/timer.c | 27 ++++++++++++++++++++++++++-
>>  1 file changed, 26 insertions(+), 1 deletion(-)
>>
>> diff --git a/arm/timer.c b/arm/timer.c
>> index f390e8e..ae1d299 100644
>> --- a/arm/timer.c
>> +++ b/arm/timer.c
>> @@ -214,21 +214,46 @@ static void test_timer(struct timer_info *info)
>>  	 * still read the pending state even if it's disabled. */
>>  	set_timer_irq_enabled(info, false);
>>  
>> +	/* Verify count goes up */
>> +	report(info->read_counter() >= now, "counter increments");
>> +
>>  	/* Enable the timer, but schedule it for much later */
>>  	info->write_cval(later);
>>  	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
>>  	isb();
>> -	report(!gic_timer_pending(info), "not pending before");
>> +	report(!gic_timer_pending(info), "not pending before 10s");
>> +
>> +	/* Check with a maximum possible cval */
>> +	info->write_cval(UINT64_MAX);
>> +	isb();
>> +	report(!gic_timer_pending(info), "not pending before UINT64_MAX");
>> +
>> +	/* also by setting tval */
>
> All the comments in this file seem to start with a capital letter.
>
>> +	info->write_tval(time_10s);
>> +	isb();
>> +	report(!gic_timer_pending(info), "not pending before 10s (via tval)");
>
> You can remove the "(via tval)" part - the message is unique enough to figure out
> which part of the test it refers to.

I added it to differentiate with the message a little further above.

>> +	report_info("TVAL is %d (delta CVAL %ld) ticks",
>> +		    info->read_tval(), info->read_cval() - info->read_counter());
>
> I'm not sure what you are trying to achieve with this. You can transform it to
> check that TVAL is indeed positive and (almost) equal to cval - cntpct, something
> like this:
>
> +	s32 tval = info->read_tval();
> +	report(tval > 0 && tval <= info->read_cval() -
> info->read_counter(), "TVAL measures time to next interrupt");

Yes it was purely informational to say tval decrements towards the next
IRQ. I can make it a pure test.

>
>>  
>> +        /* check pending once cval is before now */
>
> This comment adds nothing to the test.

dropped.

>
>>  	info->write_cval(now - 1);
>>  	isb();
>>  	report(gic_timer_pending(info), "interrupt signal pending");
>> +	report_info("TVAL is %d ticks", info->read_tval());
>
> You can test that TVAL is negative here instead of printing the value.

ok.

>
>>  
>>  	/* Disable the timer again and prepare to take interrupts */
>>  	info->write_ctl(0);
>>  	set_timer_irq_enabled(info, true);
>>  	report(!gic_timer_pending(info), "interrupt signal no longer pending");
>>  
>> +	/* QEMU bug when cntvoff_el2 > 0
>> +	 * https://bugs.launchpad.net/bugs/1859021 */
>
> This looks confusing to me. From the commit message, I got that kvm-unit-tests
> needs qemu to set a special value for CNTVOFF_EL2. But the comments seems to
> suggest that kvm-unit-tests can trigger the bug without qemu doing anything
> special. Can you elaborate under which condition kvm-unit-tests can
> trigger the bug?

It can't without some sort of mechanism to set the hypervisor registers
before running the test. The QEMU bug is an overflow when cval of UINT64_MAX
with a non-zero CNTVOFF_EL2.

Running under KVM the host kernel will have likely set CNTVOFF_EL2 to
some sort of value with:

	update_vtimer_cntvoff(vcpu, kvm_phys_timer_read());

>
>> +	info->write_ctl(ARCH_TIMER_CTL_ENABLE);
>> +	info->write_cval(UINT64_MAX);
>
> The order is wrong - you write CVAL first, *then* enable to timer. Otherwise you
> might get an interrupt because of the previous CVAL value.
>
> The previous value for CVAL was now -1, so your change triggers an unwanted
> interrupt after enabling the timer. The interrupt handler masks the timer
> interrupt at the timer level, which means that as far as the gic is concerned the
> interrupt is not pending, making the report call afterwards useless.
>
>> +	isb();
>> +	report(!gic_timer_pending(info), "not pending before UINT64_MAX (irqs on)");
>
> This check can be improved. You want to check the timer CTL.ISTATUS here, not the
> gic. A device (in this case, the timer) can assert the interrupt, but the gic does
> not sample it immediately. Come to think of it, the entire timer test is wrong
> because of this.

Is it worth still checking the GIC or just replacing everything with
calls to:

  static bool timer_pending(struct timer_info *info)
  {
          return info->read_ctl() & ARCH_TIMER_CTL_ISTATUS;
  }

>
> Thanks,
> Alex
>> +	info->write_ctl(0);
>> +
>>  	report(test_cval_10msec(info), "latency within 10 ms");
>>  	report(info->irq_received, "interrupt received");
>>  


-- 
Alex Bennée

^ permalink raw reply	[flat|nested] 4+ messages in thread

end of thread, back to index

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-01-10 16:05 [kvm-unit-tests PATCH] arm: expand the timer tests Alex Bennée
2020-01-13 13:48 ` Alexandru Elisei
2020-01-13 14:07   ` Alexandru Elisei
2020-01-13 17:38   ` Alex Bennée

KVM Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/kvm/0 kvm/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 kvm kvm/ https://lore.kernel.org/kvm \
		kvm@vger.kernel.org
	public-inbox-index kvm

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.kvm


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git