Hi,
Kernel’s printk uses local_clock() for timestamps and it is mapped to
sched_clock(). Two problems/requirements I see,
One, Kernel’s printk timestamps start from 0, I want to change this to
match with actual time since boot.
Two, sched_clock() doesn’t account for time spend in low power
state(suspend to ram)
Could workout patches to modify these behaviours and found working in
my system. But need to hear expert opinion on why this is not done in
the upstream.
diff --git a/kernel/time/sched_clock.c b/kernel/time/sched_clock.c
index 68d6c1190ac7..b63b2ded5727 100644
--- a/kernel/time/sched_clock.c
+++ b/kernel/time/sched_clock.c
@@ -190,7 +190,10 @@ sched_clock_register(u64 (*read)(void), int bits,
unsigned long rate)
/* Update epoch for new counter and update 'epoch_ns' from old counter*/
new_epoch = read();
cyc = cd.actual_read_sched_clock();
- ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
rd.sched_clock_mask, rd.mult, rd.shift);
+ if (!cyc)
+ ns = cyc_to_ns(new_epoch, new_mult, new_shift)
+ else
+ ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
rd.sched_clock_mask, rd.mult, rd.shift);
cd.actual_read_sched_clock = read;
rd.read_sched_clock = read;
@@ -287,7 +290,6 @@ void sched_clock_resume(void)
{
struct clock_read_data *rd = &cd.read_data[0];
- rd->epoch_cyc = cd.actual_read_sched_clock();
hrtimer_start(&sched_clock_timer, cd.wrap_kt, HRTIMER_MODE_REL_HARD);
rd->read_sched_clock = cd.actual_read_sched_clock;
}
Regards,
Arun
CCing maintainers
On Wed, Jul 19, 2023 at 10:36 AM Arun KS <[email protected]> wrote:
>
> Hi,
>
> Kernel’s printk uses local_clock() for timestamps and it is mapped to
> sched_clock(). Two problems/requirements I see,
>
> One, Kernel’s printk timestamps start from 0, I want to change this to
> match with actual time since boot.
> Two, sched_clock() doesn’t account for time spend in low power
> state(suspend to ram)
>
> Could workout patches to modify these behaviours and found working in
> my system. But need to hear expert opinion on why this is not done in
> the upstream.
>
> diff --git a/kernel/time/sched_clock.c b/kernel/time/sched_clock.c
> index 68d6c1190ac7..b63b2ded5727 100644
> --- a/kernel/time/sched_clock.c
> +++ b/kernel/time/sched_clock.c
> @@ -190,7 +190,10 @@ sched_clock_register(u64 (*read)(void), int bits,
> unsigned long rate)
> /* Update epoch for new counter and update 'epoch_ns' from old counter*/
> new_epoch = read();
> cyc = cd.actual_read_sched_clock();
> - ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> rd.sched_clock_mask, rd.mult, rd.shift);
> + if (!cyc)
> + ns = cyc_to_ns(new_epoch, new_mult, new_shift)
> + else
> + ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> rd.sched_clock_mask, rd.mult, rd.shift);
> cd.actual_read_sched_clock = read;
>
> rd.read_sched_clock = read;
>
> @@ -287,7 +290,6 @@ void sched_clock_resume(void)
> {
> struct clock_read_data *rd = &cd.read_data[0];
>
> - rd->epoch_cyc = cd.actual_read_sched_clock();
> hrtimer_start(&sched_clock_timer, cd.wrap_kt, HRTIMER_MODE_REL_HARD);
> rd->read_sched_clock = cd.actual_read_sched_clock;
> }
>
> Regards,
> Arun
On Thu, Jul 20, 2023 at 03:54:56PM +0530, Arun KS wrote:
> CCing maintainers
>
> On Wed, Jul 19, 2023 at 10:36 AM Arun KS <[email protected]> wrote:
> >
> > Hi,
> >
> > Kernel’s printk uses local_clock() for timestamps and it is mapped to
> > sched_clock(). Two problems/requirements I see,
> >
> > One, Kernel’s printk timestamps start from 0, I want to change this to
> > match with actual time since boot.
You can fundamentally only consistently tell time since the clock gets
initialized. Starting at 0 is what you get.
> > Two, sched_clock() doesn’t account for time spend in low power
> > state(suspend to ram)
Why would we do that? The next person will complain that they don't want
this. Then another person complains they also want time spend in
suspend-to-disk, and another person wants a pony.
> >
> > Could workout patches to modify these behaviours and found working in
> > my system. But need to hear expert opinion on why this is not done in
> > the upstream.
> >
> > diff --git a/kernel/time/sched_clock.c b/kernel/time/sched_clock.c
> > index 68d6c1190ac7..b63b2ded5727 100644
> > --- a/kernel/time/sched_clock.c
> > +++ b/kernel/time/sched_clock.c
This is only one of many sched_clock implementations...
> > @@ -190,7 +190,10 @@ sched_clock_register(u64 (*read)(void), int bits,
> > unsigned long rate)
> > /* Update epoch for new counter and update 'epoch_ns' from old counter*/
> > new_epoch = read();
> > cyc = cd.actual_read_sched_clock();
> > - ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> > rd.sched_clock_mask, rd.mult, rd.shift);
> > + if (!cyc)
> > + ns = cyc_to_ns(new_epoch, new_mult, new_shift)
> > + else
> > + ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> > rd.sched_clock_mask, rd.mult, rd.shift);
> > cd.actual_read_sched_clock = read;
> >
> > rd.read_sched_clock = read;
> >
> > @@ -287,7 +290,6 @@ void sched_clock_resume(void)
> > {
> > struct clock_read_data *rd = &cd.read_data[0];
> >
> > - rd->epoch_cyc = cd.actual_read_sched_clock();
And what if you've been suspended long enough to wrap the clock ?!?
> > hrtimer_start(&sched_clock_timer, cd.wrap_kt, HRTIMER_MODE_REL_HARD);
> > rd->read_sched_clock = cd.actual_read_sched_clock;
> > }
> >
> > Regards,
> > Arun
On Thu, Jul 20, 2023 at 4:07 PM Peter Zijlstra <[email protected]> wrote:
>
> On Thu, Jul 20, 2023 at 03:54:56PM +0530, Arun KS wrote:
> > CCing maintainers
> >
> > On Wed, Jul 19, 2023 at 10:36 AM Arun KS <[email protected]> wrote:
> > >
> > > Hi,
> > >
> > > Kernel’s printk uses local_clock() for timestamps and it is mapped to
> > > sched_clock(). Two problems/requirements I see,
> > >
> > > One, Kernel’s printk timestamps start from 0, I want to change this to
> > > match with actual time since boot.
>
> You can fundamentally only consistently tell time since the clock gets
> initialized. Starting at 0 is what you get.
>
> > > Two, sched_clock() doesn’t account for time spend in low power
> > > state(suspend to ram)
>
> Why would we do that? The next person will complain that they don't want
> this. Then another person complains they also want time spend in
> suspend-to-disk, and another person wants a pony.
Thanks Peter, Got your point. I was trying to understand if there are
any other side effects of doing this downstream.
>
> > >
> > > Could workout patches to modify these behaviours and found working in
> > > my system. But need to hear expert opinion on why this is not done in
> > > the upstream.
> > >
> > > diff --git a/kernel/time/sched_clock.c b/kernel/time/sched_clock.c
> > > index 68d6c1190ac7..b63b2ded5727 100644
> > > --- a/kernel/time/sched_clock.c
> > > +++ b/kernel/time/sched_clock.c
>
> This is only one of many sched_clock implementations...
>
> > > @@ -190,7 +190,10 @@ sched_clock_register(u64 (*read)(void), int bits,
> > > unsigned long rate)
> > > /* Update epoch for new counter and update 'epoch_ns' from old counter*/
> > > new_epoch = read();
> > > cyc = cd.actual_read_sched_clock();
> > > - ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> > > rd.sched_clock_mask, rd.mult, rd.shift);
> > > + if (!cyc)
> > > + ns = cyc_to_ns(new_epoch, new_mult, new_shift)
> > > + else
> > > + ns = rd.epoch_ns + cyc_to_ns((cyc - rd.epoch_cyc) &
> > > rd.sched_clock_mask, rd.mult, rd.shift);
> > > cd.actual_read_sched_clock = read;
> > >
> > > rd.read_sched_clock = read;
> > >
> > > @@ -287,7 +290,6 @@ void sched_clock_resume(void)
> > > {
> > > struct clock_read_data *rd = &cd.read_data[0];
> > >
> > > - rd->epoch_cyc = cd.actual_read_sched_clock();
>
> And what if you've been suspended long enough to wrap the clock ?!?
Fair point. Will take a note.
>
> > > hrtimer_start(&sched_clock_timer, cd.wrap_kt, HRTIMER_MODE_REL_HARD);
> > > rd->read_sched_clock = cd.actual_read_sched_clock;
> > > }
> > >
> > > Regards,
> > > Arun