Le 06/10/2023 à 18:22, Hari Bathini a écrit :
> Hi Christophe,
>
>
> On 29/09/23 2:09 pm, Christophe Leroy wrote:
>>
>>
>> Le 28/09/2023 à 21:48, Hari Bathini a écrit :
>>> patch_instruction() entails setting up pte, patching the instruction,
>>> clearing the pte and flushing the tlb. If multiple instructions need
>>> to be patched, every instruction would have to go through the above
>>> drill unnecessarily. Instead, introduce function patch_instructions()
>>> that sets up the pte, clears the pte and flushes the tlb only once per
>>> page range of instructions to be patched. This adds a slight overhead
>>> to patch_instruction() call while improving the patching time for
>>> scenarios where more than one instruction needs to be patched.
>>
>> On my powerpc8xx, this patch leads to an increase of about 8% of the
>> time needed to activate ftrace function tracer.
>
> Interesting! My observation on ppc64le was somewhat different.
> With single cpu, average ticks were almost similar with and without
> the patch (~1580). I saw a performance degradation of less than
> 0.6% without vs with this patch to activate function tracer.
>
> Ticks to activate function tracer in 15 attempts without
> this patch (avg: 108734089):
> 106619626
> 111712292
> 111030404
> 111021344
> 111313530
> 106253773
> 107156175
> 106887038
> 107215379
> 108646636
> 108040287
> 108311770
> 107842343
> 106894310
> 112066423
>
> Ticks to activate function tracer in 15 attempts with
> this patch (avg: 109328578):
> 109378357
> 108794095
> 108595381
> 107622142
> 110689418
> 107287276
> 107132093
> 112540481
> 111311830
> 112608265
> 102883923
> 112054554
> 111762570
> 109874309
> 107393979
>
> I used the below patch for the experiment:
I do the measurement at a higher level:
diff --git a/arch/powerpc/kernel/trace/ftrace.c
b/arch/powerpc/kernel/trace/ftrace.c
index 82010629cf88..3eea5b963bfa 100644
--- a/arch/powerpc/kernel/trace/ftrace.c
+++ b/arch/powerpc/kernel/trace/ftrace.c
@@ -167,7 +167,9 @@ void ftrace_replace_code(int enable)
struct ftrace_rec_iter *iter;
struct dyn_ftrace *rec;
int ret = 0, update;
+ long t0;
+ t0 = mftb();
for_ftrace_rec_iter(iter) {
rec = ftrace_rec_iter_record(iter);
ip = rec->ip;
@@ -206,6 +208,8 @@ void ftrace_replace_code(int enable)
if (ret)
goto out;
}
+ t0 = mftb() - t0;
+ pr_err("%s: %ld\n", __func__, t0);
out:
if (ret)
Without your patch I get:
# echo function > /sys/kernel/debug/tracing/current_tracer
[ 59.871176] ftrace-powerpc: ftrace_replace_code: 708099
# echo nop > /sys/kernel/debug/tracing/current_tracer
[ 62.645293] ftrace-powerpc: ftrace_replace_code: 606449
[ 64.141428] ftrace-powerpc: ftrace_replace_code: 710117
[ 65.185562] ftrace-powerpc: ftrace_replace_code: 615069
[ 66.311363] ftrace-powerpc: ftrace_replace_code: 706974
[ 67.272770] ftrace-powerpc: ftrace_replace_code: 604744
[ 68.311403] ftrace-powerpc: ftrace_replace_code: 707498
[ 69.245960] ftrace-powerpc: ftrace_replace_code: 607089
[ 72.661438] ftrace-powerpc: ftrace_replace_code: 710228
[ 74.127413] ftrace-powerpc: ftrace_replace_code: 604846
[ 75.301460] ftrace-powerpc: ftrace_replace_code: 707982
[ 76.289665] ftrace-powerpc: ftrace_replace_code: 600860
[ 77.431054] ftrace-powerpc: ftrace_replace_code: 706672
[ 78.418618] ftrace-powerpc: ftrace_replace_code: 600879
[ 79.641558] ftrace-powerpc: ftrace_replace_code: 711074
[ 80.636932] ftrace-powerpc: ftrace_replace_code: 605791
[ 81.751581] ftrace-powerpc: ftrace_replace_code: 709184
[ 82.802525] ftrace-powerpc: ftrace_replace_code: 603046
[ 84.701412] ftrace-powerpc: ftrace_replace_code: 709887
[ 85.792599] ftrace-powerpc: ftrace_replace_code: 604801
With patch_instructions() patch applied I get:
[ 150.677364] ftrace-powerpc: ftrace_replace_code: 753321
[ 154.201196] ftrace-powerpc: ftrace_replace_code: 657561
[ 157.027344] ftrace-powerpc: ftrace_replace_code: 753435
[ 158.692425] ftrace-powerpc: ftrace_replace_code: 652702
[ 162.137339] ftrace-powerpc: ftrace_replace_code: 753394
[ 163.207269] ftrace-powerpc: ftrace_replace_code: 650320
[ 165.387861] ftrace-powerpc: ftrace_replace_code: 756018
[ 166.458877] ftrace-powerpc: ftrace_replace_code: 650477
[ 167.617375] ftrace-powerpc: ftrace_replace_code: 753326
[ 168.596360] ftrace-powerpc: ftrace_replace_code: 647984
[ 169.737676] ftrace-powerpc: ftrace_replace_code: 756137
[ 170.743584] ftrace-powerpc: ftrace_replace_code: 652650
[ 171.907454] ftrace-powerpc: ftrace_replace_code: 754017
[ 172.943305] ftrace-powerpc: ftrace_replace_code: 650853
[ 174.187347] ftrace-powerpc: ftrace_replace_code: 753476
[ 175.811981] ftrace-powerpc: ftrace_replace_code: 650908
[ 177.007400] ftrace-powerpc: ftrace_replace_code: 753408
[ 177.993642] ftrace-powerpc: ftrace_replace_code: 651607
[ 179.157650] ftrace-powerpc: ftrace_replace_code: 755624
[ 180.141799] ftrace-powerpc: ftrace_replace_code: 652184
Christophe
>
> diff --git a/arch/powerpc/lib/code-patching.c
> b/arch/powerpc/lib/code-patching.c
> index b00112d7ad4..0979d12d00c 100644
> --- a/arch/powerpc/lib/code-patching.c
> +++ b/arch/powerpc/lib/code-patching.c
> @@ -19,6 +19,10 @@
> #include <asm/page.h>
> #include <asm/code-patching.h>
> #include <asm/inst.h>
> +#include <asm/time.h>
> +
> +unsigned long patching_time;
> +unsigned long num_times;
>
> static int __patch_instruction(u32 *exec_addr, ppc_inst_t instr, u32
> *patch_addr)
> {
> @@ -353,7 +357,7 @@ static int __do_patch_instruction(u32 *addr,
> ppc_inst_t instr)
> return err;
> }
>
> -int patch_instruction(u32 *addr, ppc_inst_t instr)
> +int ___patch_instruction(u32 *addr, ppc_inst_t instr)
> {
> int err;
> unsigned long flags;
> @@ -376,6 +380,19 @@ int patch_instruction(u32 *addr, ppc_inst_t instr)
>
> return err;
> }
> +
> +int patch_instruction(u32 *addr, ppc_inst_t instr)
> +{
> + u64 start;
> + int err;
> +
> + start = get_tb();
> + err = ___patch_instruction(addr, instr);
> + patching_time += (get_tb() - start);
> + num_times++;
> +
> + return err;
> +}
> NOKPROBE_SYMBOL(patch_instruction);
>
> int patch_branch(u32 *addr, unsigned long target, int flags)
> diff --git a/kernel/ksysfs.c b/kernel/ksysfs.c
> index 1d4bc493b2f..f52694cfeab 100644
> --- a/kernel/ksysfs.c
> +++ b/kernel/ksysfs.c
> @@ -35,6 +35,18 @@ static struct kobj_attribute _name##_attr =
> __ATTR_RO(_name)
> #define KERNEL_ATTR_RW(_name) \
> static struct kobj_attribute _name##_attr = __ATTR_RW(_name)
>
> +unsigned long patch_avgtime;
> +extern unsigned long patching_time;
> +extern unsigned long num_times;
> +
> +static ssize_t patching_avgtime_show(struct kobject *kobj,
> + struct kobj_attribute *attr, char *buf)
> +{
> + patch_avgtime = patching_time / num_times;
> + return sysfs_emit(buf, "%lu\n", patch_avgtime);
> +}
> +KERNEL_ATTR_RO(patching_avgtime);
> +
> /* current uevent sequence number */
> static ssize_t uevent_seqnum_show(struct kobject *kobj,
> struct kobj_attribute *attr, char *buf)
> @@ -250,6 +262,7 @@ struct kobject *kernel_kobj;
> EXPORT_SYMBOL_GPL(kernel_kobj);
>
> static struct attribute * kernel_attrs[] = {
> + &patching_avgtime_attr.attr,
> &fscaps_attr.attr,
> &uevent_seqnum_attr.attr,
> &cpu_byteorder_attr.attr,
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index abaaf516fca..5eb950bcab9 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -50,6 +50,7 @@
> #include <linux/workqueue.h>
>
> #include <asm/setup.h> /* COMMAND_LINE_SIZE */
> +#include <asm/time.h>
>
> #include "trace.h"
> #include "trace_output.h"
> @@ -6517,6 +6518,7 @@ int tracing_set_tracer(struct trace_array *tr,
> const char *buf)
> bool had_max_tr;
> #endif
> int ret = 0;
> + u64 start;
>
> mutex_lock(&trace_types_lock);
>
> @@ -6536,6 +6538,10 @@ int tracing_set_tracer(struct trace_array *tr,
> const char *buf)
> ret = -EINVAL;
> goto out;
> }
> +
> + pr_warn("Current tracer: %s, Changing to tracer: %s\n",
> + tr->current_trace->name, t->name);
> + start = get_tb();
> if (t == tr->current_trace)
> goto out;
>
> @@ -6614,6 +6620,7 @@ int tracing_set_tracer(struct trace_array *tr,
> const char *buf)
> tr->current_trace->enabled++;
> trace_branch_enable(tr);
> out:
> + pr_warn("Time taken to enable tracer is %llu\n", (get_tb() - start));
> mutex_unlock(&trace_types_lock);
>
> return ret;
>
> Thanks
> Hari
