| Message ID | 1401903034-20074-1-git-send-email-dianders@chromium.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
On 06/04/2014 07:30 PM, Doug Anderson wrote: > In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we > supported using the MCT as a scheduler clock. We properly marked > exynos4_read_sched_clock() as notrace. However, we then went and > called another function that _wasn't_ notrace. That means if you do: > > cd /sys/kernel/debug/tracing/ > echo function_graph > current_tracer > > You'll get a crash. > > Fix this (but still let other readers of the MCT be trace-enabled) by > adding an extra function. It's important to keep other users of MCT > traceable because the MCT is actually quite slow. Hi Doug, could you elaborate ? I don't get the 'because the MCT ... slow' Thanks -- Daniel > Signed-off-by: Doug Anderson <dianders@chromium.org> > --- > drivers/clocksource/exynos_mct.c | 9 +++++++-- > 1 file changed, 7 insertions(+), 2 deletions(-) > > diff --git a/drivers/clocksource/exynos_mct.c b/drivers/clocksource/exynos_mct.c > index 8d64200..ba3a683 100644 > --- a/drivers/clocksource/exynos_mct.c > +++ b/drivers/clocksource/exynos_mct.c > @@ -165,7 +165,7 @@ static void exynos4_mct_frc_start(u32 hi, u32 lo) > exynos4_mct_write(reg, EXYNOS4_MCT_G_TCON); > } > > -static cycle_t exynos4_frc_read(struct clocksource *cs) > +static inline cycle_t notrace _exynos4_frc_read(void) > { > unsigned int lo, hi; > u32 hi2 = __raw_readl(reg_base + EXYNOS4_MCT_G_CNT_U); > @@ -179,6 +179,11 @@ static cycle_t exynos4_frc_read(struct clocksource *cs) > return ((cycle_t)hi << 32) | lo; > } > > +static cycle_t exynos4_frc_read(struct clocksource *cs) > +{ > + return _exynos4_frc_read(); > +} > + > static void exynos4_frc_resume(struct clocksource *cs) > { > exynos4_mct_frc_start(0, 0); > @@ -195,7 +200,7 @@ struct clocksource mct_frc = { > > static u64 notrace exynos4_read_sched_clock(void) > { > - return exynos4_frc_read(&mct_frc); > + return _exynos4_frc_read(); > } > > static void __init exynos4_clocksource_init(void) >
Daniel, On Sun, Jun 15, 2014 at 2:18 PM, Daniel Lezcano <daniel.lezcano@linaro.org> wrote: > On 06/04/2014 07:30 PM, Doug Anderson wrote: >> >> In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we >> supported using the MCT as a scheduler clock. We properly marked >> exynos4_read_sched_clock() as notrace. However, we then went and >> called another function that _wasn't_ notrace. That means if you do: >> >> cd /sys/kernel/debug/tracing/ >> echo function_graph > current_tracer >> >> You'll get a crash. >> >> Fix this (but still let other readers of the MCT be trace-enabled) by >> adding an extra function. It's important to keep other users of MCT >> traceable because the MCT is actually quite slow. > > > > Hi Doug, > > could you elaborate ? I don't get the 'because the MCT ... slow' Sorry, I was trying to avoid duplication in the series and it's more obvious when you look at parts 2 and 3 of the series. ;) Doing the math (please correct any miscalculations) using the numbers from the other patches: You can see that the existing code takes 1323852 us for 1000000 gettimeofday in userspace. The fastest implementation (just shaving to a 32-bit timer) gets us as fast as ~1000000 us for 1000000 gettimeofday in userspace. From profiling, I believe that gettimeofday from userspace is about 50% overhead (system call, multiplication, copies, etc) and about 50% MCT read. That means that the fastest you can possibly do an MCT read is in .5us or 500ns. I believe an A15 has something like 1 or 2 cycles per instruction. If it were 2 cycles per instruction, it can execute a normal instruction on a 2GHz machine in .5ns. That means we can execute 1000 normal instructions in the time it takes to do a since MCT access. ...so I guess that's what I'd call slow. ;) What do you think? I know that the MCT read shows up in whole system profiles of gettimeofday. -Doug
On 06/16/2014 06:40 AM, Doug Anderson wrote: > Daniel, > > On Sun, Jun 15, 2014 at 2:18 PM, Daniel Lezcano > <daniel.lezcano@linaro.org> wrote: >> On 06/04/2014 07:30 PM, Doug Anderson wrote: >>> >>> In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we >>> supported using the MCT as a scheduler clock. We properly marked >>> exynos4_read_sched_clock() as notrace. However, we then went and >>> called another function that _wasn't_ notrace. That means if you do: >>> >>> cd /sys/kernel/debug/tracing/ >>> echo function_graph > current_tracer >>> >>> You'll get a crash. >>> >>> Fix this (but still let other readers of the MCT be trace-enabled) by >>> adding an extra function. It's important to keep other users of MCT >>> traceable because the MCT is actually quite slow. >> >> >> >> Hi Doug, >> >> could you elaborate ? I don't get the 'because the MCT ... slow' > > Sorry, I was trying to avoid duplication in the series and it's more > obvious when you look at parts 2 and 3 of the series. ;) > > Doing the math (please correct any miscalculations) using the numbers > from the other patches: You can see that the existing code takes > 1323852 us for 1000000 gettimeofday in userspace. The fastest > implementation (just shaving to a 32-bit timer) gets us as fast as > ~1000000 us for 1000000 gettimeofday in userspace. > > From profiling, I believe that gettimeofday from userspace is about > 50% overhead (system call, multiplication, copies, etc) and about 50% > MCT read. That means that the fastest you can possibly do an MCT read > is in .5us or 500ns. > > I believe an A15 has something like 1 or 2 cycles per instruction. If > it were 2 cycles per instruction, it can execute a normal instruction > on a 2GHz machine in .5ns. That means we can execute 1000 normal > instructions in the time it takes to do a since MCT access. > > ...so I guess that's what I'd call slow. ;) What do you think? I > know that the MCT read shows up in whole system profiles of > gettimeofday. Hi Dough, thanks for the explanation. I still don't get why it is important to keep others users of mct traceable because it is quite slow ? May be it is what you explained here, but I miss the connection between 'the other users' <-> 'traceable' <-> 'because slow'.
Daniel, On Mon, Jun 16, 2014 at 1:52 AM, Daniel Lezcano <daniel.lezcano@linaro.org> wrote: > Hi Dough, > > thanks for the explanation. I still don't get why it is important to keep > others users of mct traceable because it is quite slow ? May be it is what > you explained here, but I miss the connection between 'the other users' <-> > 'traceable' <-> 'because slow'. It stems from the fact that one use of trace is to figure out why things are slow. In that case you want to make sure that the slow things are traceable. I can run the following: cd /sys/kernel/debug/tracing echo nop > current_tracer echo 0 > options/sleep-time echo 0 > options/graph-time echo 1 > function_profile_enabled ~/gettimeofday 100000 echo 0 > function_profile_enabled Then I can see this: Function Hit Time Avg s^2 -------- --- ---- --- --- __getnstimeofday 100005 258267.8 us 2.582 us 447196.9 us do_gettimeofday 100004 252395.6 us 2.523 us 462549.6 us SyS_gettimeofday 100004 249353.6 us 2.493 us 1223308 us getnstimeofday 100005 246217.2 us 2.462 us 369149.8 us exynos4_frc_read 101096 181620.0 us 1.796 us 157413.8 us ...if I mark exynos4_frc_read() as notrace then it doesn't show up in the profile, which is unfortunate. NOTE: the above profile is a bit misleading in terms of actual time taken my belief is that we end up with some confusing numbers since profiling uses the MCT itself (I think) to record how long a function took to execute. Despite this it's still awfully nice that exynos4_frc_read() actually shows up in the trace...
On 06/04/2014 07:30 PM, Doug Anderson wrote: > In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we > supported using the MCT as a scheduler clock. We properly marked > exynos4_read_sched_clock() as notrace. However, we then went and > called another function that _wasn't_ notrace. That means if you do: > > cd /sys/kernel/debug/tracing/ > echo function_graph > current_tracer > > You'll get a crash. > > Fix this (but still let other readers of the MCT be trace-enabled) by > adding an extra function. It's important to keep other users of MCT > traceable because the MCT is actually quite slow. Thanks for the explanation in the other email. I think the last sentence is a bit confusing because you are implicitly saying you need these traces to investigate why the timer is slow which is referring to something not related to this fix. > Signed-off-by: Doug Anderson <dianders@chromium.org> > --- > drivers/clocksource/exynos_mct.c | 9 +++++++-- > 1 file changed, 7 insertions(+), 2 deletions(-) > > diff --git a/drivers/clocksource/exynos_mct.c b/drivers/clocksource/exynos_mct.c > index 8d64200..ba3a683 100644 > --- a/drivers/clocksource/exynos_mct.c > +++ b/drivers/clocksource/exynos_mct.c > @@ -165,7 +165,7 @@ static void exynos4_mct_frc_start(u32 hi, u32 lo) > exynos4_mct_write(reg, EXYNOS4_MCT_G_TCON); > } > > -static cycle_t exynos4_frc_read(struct clocksource *cs) > +static inline cycle_t notrace _exynos4_frc_read(void) Why inline ? > { > unsigned int lo, hi; > u32 hi2 = __raw_readl(reg_base + EXYNOS4_MCT_G_CNT_U); > @@ -179,6 +179,11 @@ static cycle_t exynos4_frc_read(struct clocksource *cs) > return ((cycle_t)hi << 32) | lo; > } > > +static cycle_t exynos4_frc_read(struct clocksource *cs) > +{ > + return _exynos4_frc_read(); > +} > + > static void exynos4_frc_resume(struct clocksource *cs) > { > exynos4_mct_frc_start(0, 0); > @@ -195,7 +200,7 @@ struct clocksource mct_frc = { > > static u64 notrace exynos4_read_sched_clock(void) > { > - return exynos4_frc_read(&mct_frc); > + return _exynos4_frc_read(); > } > > static void __init exynos4_clocksource_init(void) >
Daniel, On Tue, Jun 17, 2014 at 5:13 AM, Daniel Lezcano <daniel.lezcano@linaro.org> wrote: > On 06/04/2014 07:30 PM, Doug Anderson wrote: >> >> In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we >> supported using the MCT as a scheduler clock. We properly marked >> exynos4_read_sched_clock() as notrace. However, we then went and >> called another function that _wasn't_ notrace. That means if you do: >> >> cd /sys/kernel/debug/tracing/ >> echo function_graph > current_tracer >> >> You'll get a crash. >> >> Fix this (but still let other readers of the MCT be trace-enabled) by >> adding an extra function. It's important to keep other users of MCT >> traceable because the MCT is actually quite slow. > > > Thanks for the explanation in the other email. > > I think the last sentence is a bit confusing because you are implicitly > saying you need these traces to investigate why the timer is slow which is > referring to something not related to this fix. Done >> Signed-off-by: Doug Anderson <dianders@chromium.org> >> --- >> drivers/clocksource/exynos_mct.c | 9 +++++++-- >> 1 file changed, 7 insertions(+), 2 deletions(-) >> >> diff --git a/drivers/clocksource/exynos_mct.c >> b/drivers/clocksource/exynos_mct.c >> index 8d64200..ba3a683 100644 >> --- a/drivers/clocksource/exynos_mct.c >> +++ b/drivers/clocksource/exynos_mct.c >> @@ -165,7 +165,7 @@ static void exynos4_mct_frc_start(u32 hi, u32 lo) >> exynos4_mct_write(reg, EXYNOS4_MCT_G_TCON); >> } >> >> -static cycle_t exynos4_frc_read(struct clocksource *cs) >> +static inline cycle_t notrace _exynos4_frc_read(void) > > > Why inline ? Somehow I thought that without the "inline" that somehow exynos4_frc_read() would not be traceable. ...but this makes no sense so I've removed.
diff --git a/drivers/clocksource/exynos_mct.c b/drivers/clocksource/exynos_mct.c index 8d64200..ba3a683 100644 --- a/drivers/clocksource/exynos_mct.c +++ b/drivers/clocksource/exynos_mct.c @@ -165,7 +165,7 @@ static void exynos4_mct_frc_start(u32 hi, u32 lo) exynos4_mct_write(reg, EXYNOS4_MCT_G_TCON); } -static cycle_t exynos4_frc_read(struct clocksource *cs) +static inline cycle_t notrace _exynos4_frc_read(void) { unsigned int lo, hi; u32 hi2 = __raw_readl(reg_base + EXYNOS4_MCT_G_CNT_U); @@ -179,6 +179,11 @@ static cycle_t exynos4_frc_read(struct clocksource *cs) return ((cycle_t)hi << 32) | lo; } +static cycle_t exynos4_frc_read(struct clocksource *cs) +{ + return _exynos4_frc_read(); +} + static void exynos4_frc_resume(struct clocksource *cs) { exynos4_mct_frc_start(0, 0); @@ -195,7 +200,7 @@ struct clocksource mct_frc = { static u64 notrace exynos4_read_sched_clock(void) { - return exynos4_frc_read(&mct_frc); + return _exynos4_frc_read(); } static void __init exynos4_clocksource_init(void)
In (93bfb76 clocksource: exynos_mct: register sched_clock callback) we supported using the MCT as a scheduler clock. We properly marked exynos4_read_sched_clock() as notrace. However, we then went and called another function that _wasn't_ notrace. That means if you do: cd /sys/kernel/debug/tracing/ echo function_graph > current_tracer You'll get a crash. Fix this (but still let other readers of the MCT be trace-enabled) by adding an extra function. It's important to keep other users of MCT traceable because the MCT is actually quite slow. Signed-off-by: Doug Anderson <dianders@chromium.org> --- drivers/clocksource/exynos_mct.c | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-)