Re: [PATCH 0/6] Enable CONFIG_TIMER for all Kirwood / MVEBU boards

[Tony Dinh <mibodhi@gmail.com>]

Hi Stefan R,

On Thu, Sep 1, 2022 at 7:35 AM Simon Glass <sjg@chromium.org> wrote:
>
> Hi,
>
> On Thu, 1 Sept 2022 at 03:27, Stefan Roese <sr@denx.de> wrote:
> >
> > Hi Tony,
> >
> > On 01.09.22 09:39, Tony Dinh wrote:
> >
> > <snip>
> >
> > >>> Some ideas.
> > >>>
> > >>> The get_timer() function looks wrong assigning an uint64_t to ulong.
> > >>>
> > >>> lib/time.c
> > >>>
> > >>>       static uint64_t notrace tick_to_time(uint64_t tick)
> > >>>       uint64_t notrace get_ticks(void)
> > >>>       uint64_t __weak notrace get_ticks(void)
> > >>>
> > >>>       ulong __weak get_timer(ulong base)
> > >>>       {
> > >>>               return tick_to_time(get_ticks()) - base;
> > >>>       }
> > >>>
> > >>> Most of the timer infrastructure is using uint64_t. I'm seeing this
> > >>> __weak function get_timer was invoked in Kirkwood boards. Both in
> > >>> sleep and timer commands.
> > >>
> > >> The get_ticks() thing can run at 1MHz but the timer is 1KHz, so that
> > >> is why we don't need a u64 for the timer.
>
> This is wrong, I meant that get_tbclk() can run at 1MHZ (for example).
> The tick is 1KHz.
>
> > >
> > > Thanks for your explanation! However, would you agree that code is
> > > problematic and needed some improvement ? IOW, depending what the
> > > compiler does, it might return the 1st 32 bit of the 64-bit integer
> > > result?
>
> Yes, we should really use ulong for the tick count as well. The use of
> 64-bits seems wrong (on 32-bit machines).
>
> >
> > It will return the lower 32 bits if the system is 32bit, yes.
> >
> > To check if we have a problem here, please add this (totally untested)
> > code and extend it if it makes sense:
> >
> > diff --git a/lib/time.c b/lib/time.c
> > index bbf191f67323..ef5252419f3b 100644
> > --- a/lib/time.c
> > +++ b/lib/time.c
> > @@ -146,7 +146,15 @@ int __weak timer_init(void)
> >   /* Returns time in milliseconds */
> >   ulong __weak get_timer(ulong base)
> >   {
> > -       return tick_to_time(get_ticks()) - base;
> > +       u64 ticks = get_ticks();
> > +       u64 time_ms = tick_to_time(ticks);
> > +
> > +       if (time_ms & 0xffffffff00000000ULL)
> > +               printf("ticks=%lld time_ms=%lld\n", ticks, time_ms);
> > +       if ((time_ms - base) & 0xffffffff80000000ULL)
> > +               printf("ticks=%lld time_ms=%lld base=%ld ret=%lld\n",
> > ticks, time_ms, base, time_ms - base);
> > +
> > +       return time_ms - base;
> >   }

With this patch, indeed it showed a wrap around. And the system was
frozen during the next command.

Below is the log (my annotated comment starts with ***).

<BEGIN LOG>
U-Boot 2022.10-rc3-00048-g66ccd87a9c-dirty (Sep 01 2022 - 15:44:22 -0700)
Pogoplug V4

SoC:   Kirkwood 88F6281_A1
Model: Cloud Engines PogoPlug Series 4
DRAM:  128 MiB
orion_timer_probe Clock Rate 166000000
orion_timer_probe successful
Core:  19 devices, 15 uclasses, devicetree: separate
NAND:  128 MiB
MMC:   mvsdio@90000: 0
Loading Environment from NAND... OK
In:    serial
Out:   serial
Err:   serial
pcie0.0: Link up
Net:   eth0: ethernet-controller@72000
Hit any key to stop autoboot:  0
Pogo_V4> sleep 5
do_sleep got a timer start = 14344
do_sleep delay = 5000
do_sleep delay = 5000
do_sleep sleeping...
do_sleep start 14344 curent 100
do_sleep start 14344 curent 200
<snip>
do_sleep start 14344 curent 4800
do_sleep start 14344 curent 4900
do_sleep end of sleep ... current = 5000

Pogo_V4> sleep 10
do_sleep got a timer start = 22370
do_sleep delay = 10000
do_sleep delay = 10000
do_sleep sleeping...
do_sleep start 22370 curent 100
do_sleep start 22370 curent 200
do_sleep start 22370 curent 300
do_sleep start 22370 curent 400
<snip>
do_sleep start 22370 curent 3300
do_sleep start 22370 curent 3400
do_sleep start 22370 curent 3500
ticks=188 time_ms=0 base=22370 ret=-22370
do_sleep end of sleep ... current = 4294944926

*** we are seeing wrap around here

Pogo_V4> sleep 15
do_sleep got a timer start = 15733
do_sleep delay = 15000
do_sleep delay = 15000
do_sleep sleeping...
do_sleep start 15733 curent 100
do_sleep start 15733 curent 200
do_sleep start 15733 curent 300
do_sleep start 15733 curent 400
<snip>

do_sleep start 15733 curent 9900
do_sleep start 15733 curent 10000
do_sleep start 15733 curent 10100

*** And the system was frozen here

<END LOG>

Thanks,
Tony






> >
> > At least here, you seem to have a wrap around with the 32bits AFAICT:
> >
> > > GoFlexHome> sleep 20.5
> > > do_sleep got a timer start = 15031
> > > do_sleep delay = 20000
> > > do_sleep delay = 20500
> > > do_sleep sleeping...
> > > do_sleep start 15031 current 100
> > > <snip>
> > > do_sleep start 15031 current 6400
> > > do_sleep end of sleep ... current = 4294952265
> > >
> > > *** Something strange happened here. current should be 6500, but it
> > > seems to have garbage. So the loop exits prematurely.
> >
> > 4294952265 = 0xFFFFC549!
>
> Yes this all needs a look, I think.
>
> Regards,
> Simon