Re: [Qemu-devel] regression in timer code?

["Pavel Dovgalyuk" <dovgaluk@ispras.ru>]

> -----Original Message-----
> From: Max Filippov [mailto:jcmvbkbc@gmail.com]
> Sent: Wednesday, March 14, 2018 12:41 PM
> To: Pavel Dovgalyuk
> Cc: Pavel Dovgaluk; qemu-devel
> Subject: Re: regression in timer code?
> 
> On Wed, Mar 14, 2018 at 2:07 AM, Pavel Dovgalyuk <dovgaluk@ispras.ru> wrote:
> >> From: Max Filippov [mailto:jcmvbkbc@gmail.com]
> >> the commit b39e3f34c9de7ead6a11a74aa2de78baf41d81a7
> >> ("icount: fixed saving/restoring of icount warp timers") has changed
> >> something that made timers test for target/xtensa unstable.
> >> Specifically ccount_write case in the tests/tcg/xtensa/test_timer.S
> >> now fails for me about half of the times it is run. Given that it is run
> >> under -icount I guess this is a bug. Could you please take a look?
> >>
> >> The minimal test case is available here:
> >>   http://jcmvbkbc.spb.ru/~dumb/tmp/201803131306/test_timer.tst
> >> It is run as
> >>   qemu-system-xtensa -M sim -cpu dc232b -nographic -semihosting
> >> -icount 7  -kernel ./test_timer.tst
> >
> > I investigated your test and concluded the following.
> > First, update_ccount is inaccurate opration because of the division
> > with the remainder:
> >     env->sregs[CCOUNT] = env->ccount_base +
> >         (uint32_t)((now - env->time_base) *
> >                    env->config->clock_freq_khz / 1000000);
> >
> > Therefore, the following sequence in the test may give different result depending
> > of the actual value of "now" variable.
> 
> But the expression above depends on the difference between the now
> and env->time_base, both these values are read from
>  qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) and, most importantly,
> the test is 100% deterministic, i.e. it runs under -icount and there's no
> external factors involved, no waiting for anything, not even interrupts.
> Thus the difference must be constant, i.e. I must see consistent results.
> Am I wrong somewhere?

icount is adjusted by icount_warp_rt when CPU sleeps.
These adjustments may be different in different runs.
And the first adjustment is performed at the start of the machine.
Therefore "now" value includes non-deterministic component from the beginning,
but its increments caused by instruction executions are deterministic.

> >     rsr     a3, ccount
> >     rsr     a4, ccount
> >     sub     a4, a4, a3
> >
> > Consider the code:
> >
> > test ccount_write
> >     rsr     a3, ccount
> >     rsr     a4, ccount
> >     sub     a4, a4, a3 ; usually 1, but sometimes 2 because of rounding
> >     movi    a2, 0x12345678
> >     wsr     a2, ccount
> >     esync
> >     rsr     a3, ccount
> >     sub     a3, a3, a2 ; usually 3 (esync + yield + rsr), but sometimes 4 because of
> rounding
> >     slli    a4, a4, 2  ; 4 or 8
> >     assert  ltu, a3, a4 ; (3 or 4) < (4 or 8) ?
> > test_end
> >
> > Therefore in some cases we get a4=4 and a3=4 that forces the test to fail.

Pavel Dovgalyuk