diff mbox

[1/3] clocksource: exynos_mct: Fix ftrace

Message ID 1401903034-20074-1-git-send-email-dianders@chromium.org (mailing list archive)
State New, archived
Headers show

Commit Message

Doug Anderson June 4, 2014, 5:30 p.m. UTC
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(-)

Comments

Daniel Lezcano June 15, 2014, 9:18 p.m. UTC | #1
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)
>
Doug Anderson June 16, 2014, 4:40 a.m. UTC | #2
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
--
To unsubscribe from this list: send the line "unsubscribe linux-samsung-soc" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Daniel Lezcano June 16, 2014, 8:52 a.m. UTC | #3
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'.
Doug Anderson June 16, 2014, 4:35 p.m. UTC | #4
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...
--
To unsubscribe from this list: send the line "unsubscribe linux-samsung-soc" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Daniel Lezcano June 17, 2014, 12:13 p.m. UTC | #5
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)
>
Doug Anderson June 19, 2014, 5:07 p.m. UTC | #6
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.
--
To unsubscribe from this list: send the line "unsubscribe linux-samsung-soc" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

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)