[PATCH v5 3/3] PM/runtime:Replace jiffies based accounting with ktime based accounting

[Vincent Guittot]

On Mon, 21 Jan 2019 at 23:53, Rafael J. Wysocki <rafael at kernel.org> wrote:
>
> On Mon, Jan 21, 2019 at 4:17 PM Vincent Guittot
> <vincent.guittot at linaro.org> wrote:
> >
> > On Fri, 18 Jan 2019 at 13:08, Guenter Roeck <linux at roeck-us.net> wrote:
> > >
> > > On 1/18/19 3:05 AM, Rafael J. Wysocki wrote:
> > > > On Fri, Jan 18, 2019 at 11:53 AM Vincent Guittot
> > > > <vincent.guittot at linaro.org> wrote:
> > > >>
> > > >> On Fri, 18 Jan 2019 at 11:42, Vincent Guittot
> > > >> <vincent.guittot at linaro.org> wrote:
> > > >>>
> > > >>> Hi Guenter,
> > > >>>
> > > >>> Le Thursday 17 Jan 2019 à 14:16:28 (-0800), Guenter Roeck a écrit :
> > > >>>> On Fri, Dec 21, 2018 at 11:33:56AM +0100, Vincent Guittot wrote:
> > > >>>>> From: Thara Gopinath <thara.gopinath at linaro.org>
> > > >>>>>
> > > >>>>> This patch replaces jiffies based accounting for runtime_active_time
> > > >>>>> and runtime_suspended_time with ktime base accounting. This makes the
> > > >>>>> runtime debug counters inline with genpd and other pm subsytems which
> > > >>>>> uses ktime based accounting.
> > > >>>>>
> > > >>>>> timekeeping is initialized before pm_runtime_init() so ktime_get() will
> > > >>>>> be ready before first call. In fact, timekeeping_init() is called early
> > > >>>>> in start_kernel() which is way before driver_init() (and that's when
> > > >>>>> devices can start to be initialized) called from rest_init() via
> > > >>>>> kernel_init_freeable() and do_basic_setup().
> > > >>>>>
> > > >>>> This is not (always) correct. My qemu "collie" boot test fails with this
> > > >>>> patch applied. Reverting the patch fixes the problem. Bisect log attached.
> > > >>>>
> > > >>>
> > > >>> Can you try the patch below ?
> > > >>> ktime_get_mono_fast_ns() has the advantage of being init with dummy clock so
> > > >>> it can be used at early_init.
> > > >>
> > > >> Another possibility would be delay the init of the gpiochip
> > > >
> > > > Well, right.
> > > >
> > > > Initializing devices before timekeeping doesn't feel particularly
> > > > robust from the design perspective.
> > > >
> > > > How exactly does that happen?
> > > >
> > >
> > > With an added 'initialized' flag and backtrace into the timekeeping code,
> > > with the change suggested earlier applied:
> > >
> > > ------------[ cut here ]------------
> > > WARNING: CPU: 0 PID: 0 at kernel/time/timekeeping.c:453 ktime_get_mono_fast_ns+0x114/0x12c
> > > Timekeeping not initialized
> > > CPU: 0 PID: 0 Comm: swapper Not tainted 5.0.0-rc2-next-20190117-dirty #2
> > > Hardware name: Sharp-Collie
> > > Backtrace:
> > > [<c000dce8>] (dump_backtrace) from [<c000df78>] (show_stack+0x18/0x1c)
> > >   r7:00000009 r6:00000000 r5:c065ba90 r4:c06d3e54
> > > [<c000df60>] (show_stack) from [<c0588930>] (dump_stack+0x20/0x28)
> > > [<c0588910>] (dump_stack) from [<c0018ae8>] (__warn+0xcc/0xf4)
> > > [<c0018a1c>] (__warn) from [<c0018b5c>] (warn_slowpath_fmt+0x4c/0x6c)
> > >   r8:df407b08 r7:00000000 r6:c0c01550 r5:c065bad8 r4:c06dd028
> > > [<c0018b14>] (warn_slowpath_fmt) from [<c0069e2c>] (ktime_get_mono_fast_ns+0x114/0x12c)
> > >   r3:00000000 r2:c065bad8
> > >   r5:00000000 r4:df407b08
> > > [<c0069d18>] (ktime_get_mono_fast_ns) from [<c03c7810>] (pm_runtime_init+0x38/0xb8)
> > >   r9:c06c9a5c r8:df407b08 r7:00000000 r6:c0c01550 r5:00000000 r4:df407b08
> > > [<c03c77d8>] (pm_runtime_init) from [<c03b6a34>] (device_initialize+0xb0/0xec)
> > >   r7:00000000 r6:c0c01550 r5:00000000 r4:df407b08
> > > [<c03b6984>] (device_initialize) from [<c0366d30>] (gpiochip_add_data_with_key+0x9c/0x884)
> > >   r7:00000000 r6:c06fca34 r5:00000000 r4:00000000
> > > [<c0366c94>] (gpiochip_add_data_with_key) from [<c06b9708>] (sa1100_init_gpio+0x40/0x98)
> > >   r10:dfffcd60 r9:c06c9a5c r8:c06dd020 r7:c06dd028 r6:ffffffff r5:00000000
> > >   r4:c06fca34
> > > [<c06b96c8>] (sa1100_init_gpio) from [<c06ae58c>] (sa1100_init_irq+0x2c/0x3c)
> > >   r7:c06dd028 r6:ffffffff r5:c0713300 r4:c06e1070
> > > [<c06ae560>] (sa1100_init_irq) from [<c06aab1c>] (init_IRQ+0x20/0x28)
> > >   r5:c0713300 r4:00000000
> > > [<c06aaafc>] (init_IRQ) from [<c06a7cd0>] (start_kernel+0x254/0x4cc)
> > > [<c06a7a7c>] (start_kernel) from [<00000000>] (  (null))
> > >   r10:0000717f r9:6901b119 r8:c0000100 r7:00000092 r6:0000313d r5:00000053
> > >   r4:c06a7330
> > > ---[ end trace 91e1bd00dd7cce32 ]---
> >
> > Does it means that only the pm_runtime_init is done before
> > timekeeping_init() but no update_pm_runtime_accounting() ?
>
> This platform calls device_initialize(), via sa1100_init_irq(), from
> init_IRQ() which is in the start_kernel() code path before
> timekeeping_init().  That's the initialization of structure fields
> alone.
>
> Runtime PM really cannot be used legitimately before driver_init(),
> because it needs bus types to be there at least.
>
> > In this case, we can keep using ktimeçget in
> > update_pm_runtime_accounting() and find a solution to deal with
> > early_call of pm_runtime_init()
>
> Given the above, I think that initializing accounting_timestamp in
> pm_runtime_init() to anything different from 0 is a mistake.

I agree

>
> Note that update_pm_runtime_accounting() ignores the delta value if
> power.disable_depth is not zero anyway, so it really should be
> sufficient to update accounting_timestamp when enabling runtime PM -
> and I'm not sure why it is not updated in pm_runtime_enable() for that
> matter (that looks like a bug to me).

That's sounds reasonable to me. I'm going to add a patch to add this
changes before moving to ktime_get