Messages in this thread Patch in this message | | | Date | Thu, 2 Dec 2021 12:58:00 -0500 | From | Steven Rostedt <> | Subject | Re: [PATCH v6 1/2] scripts: ftrace - move the sort-processing in ftrace_init |
| |
On Thu, 2 Dec 2021 10:16:05 +0800 Yinan Liu <yinan@linux.alibaba.com> wrote:
> When the kernel starts, the initialization of ftrace takes > up a portion of the time (approximately 6~8ms) to sort mcount > addresses. We can save this time by moving mcount-sorting to > compile time. > > Signed-off-by: Yinan Liu <yinan@linux.alibaba.com> > Reported-by: kernel test robot <lkp@intel.com>
After applying this, I get a failure on the kprobe self tests at boot up:
Testing ftrace filter: OK trace_kprobe: Testing kprobe tracing: trace_kprobe: Could not probe notrace function kprobe_trace_selftest_target ------------[ cut here ]------------ WARNING: CPU: 2 PID: 1 at kernel/trace/trace_kprobe.c:1973 kprobe_trace_self_tests_init+0x5c/0x497 Modules linked in: CPU: 2 PID: 1 Comm: swapper/0 Tainted: G W 5.16.0-rc3-test+ #40 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016 RIP: 0010:kprobe_trace_self_tests_init+0x5c/0x497 Code: 5f d7 94 ff 00 0f 85 48 04 00 00 48 c7 c7 c0 ff 8e 88 e8 6b bb cd fd 48 c7 c7 20 00 8f 88 e8 a9 b6 db fc 41 89 c4 85 c0 74 16 <0f> 0b 48 c7 c7 a0 00 8f 88 41 bc 01 00 00 00 e8 44 bb cd fd eb 33 RSP: 0000:ffffc90000037d00 EFLAGS: 00010282 RAX: 00000000ffffffea RBX: 0000000000000000 RCX: dffffc0000000000 RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff8880c2b33eb4 RBP: 1ffff92000006fa9 R08: ffffffff872e1900 R09: 0000000080000171 R10: fffff52000006f15 R11: 0000000000000001 R12: 00000000ffffffea R13: 0000000000000007 R14: ffffffff8a608098 R15: ffffffff8a6080a0 FS: 0000000000000000(0000) GS:ffff8880c2b00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 0000000000000000 CR3: 000000009260e001 CR4: 00000000001706e0 Call Trace: <TASK> ? init_kprobe_trace+0x1c4/0x1c4 do_one_initcall+0x89/0x2b0 ? trace_event_raw_event_initcall_finish+0x150/0x150 ? parameq+0x90/0x90 ? _raw_spin_unlock_irqrestore+0x19/0x40 kernel_init_freeable+0x35a/0x3e7 ? console_on_rootfs+0x52/0x52 ? _raw_spin_unlock+0x30/0x30 ? rest_init+0xf0/0xf0 ? rest_init+0xf0/0xf0 kernel_init+0x19/0x140 ret_from_fork+0x22/0x30 </TASK> ---[ end trace 27c06839fac37d16 ]---
Config attached.
-- Steve
> --- > kernel/trace/ftrace.c | 11 +++- > scripts/Makefile | 2 +- > scripts/link-vmlinux.sh | 6 +- > scripts/sorttable.c | 2 + > scripts/sorttable.h | 120 +++++++++++++++++++++++++++++++++++++++- > 5 files changed, 133 insertions(+), 8 deletions(-) > > diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c > index 7b180f61e6d3..c0f95cae68b5 100644 > --- a/kernel/trace/ftrace.c > +++ b/kernel/trace/ftrace.c > @@ -6189,8 +6189,15 @@ static int ftrace_process_locs(struct module *mod, > if (!count) > return 0; > > - sort(start, count, sizeof(*start), > - ftrace_cmp_ips, NULL); > + /* > + * Sorting mcount in vmlinux at build time depend on > + * CONFIG_BUILDTIME_TABLE_SORT, while mcount loc in > + * modules can not be sorted at build time. > + */ > + if (!IS_ENABLED(CONFIG_BUILDTIME_TABLE_SORT) || mod) { > + sort(start, count, sizeof(*start), > + ftrace_cmp_ips, NULL); > + } > > start_pg = ftrace_allocate_pages(count); > if (!start_pg) > diff --git a/scripts/Makefile b/scripts/Makefile > index 9adb6d247818..b286e112e3b0 100644 > --- a/scripts/Makefile > +++ b/scripts/Makefile > @@ -17,6 +17,7 @@ hostprogs-always-$(CONFIG_SYSTEM_EXTRA_CERTIFICATE) += insert-sys-cert > hostprogs-always-$(CONFIG_SYSTEM_REVOCATION_LIST) += extract-cert > > HOSTCFLAGS_sorttable.o = -I$(srctree)/tools/include > +HOSTLDLIBS_sorttable = -lpthread > HOSTCFLAGS_asn1_compiler.o = -I$(srctree)/include > HOSTCFLAGS_sign-file.o = $(CRYPTO_CFLAGS) > HOSTLDLIBS_sign-file = $(CRYPTO_LIBS) > @@ -29,7 +30,6 @@ ARCH := x86 > endif > HOSTCFLAGS_sorttable.o += -I$(srctree)/tools/arch/x86/include > HOSTCFLAGS_sorttable.o += -DUNWINDER_ORC_ENABLED > -HOSTLDLIBS_sorttable = -lpthread > endif > > # The following programs are only built on demand > diff --git a/scripts/link-vmlinux.sh b/scripts/link-vmlinux.sh > index 36ef7b37fc5d..e2e1a8f39f15 100755 > --- a/scripts/link-vmlinux.sh > +++ b/scripts/link-vmlinux.sh > @@ -422,6 +422,9 @@ if [ -n "${CONFIG_DEBUG_INFO_BTF}" -a -n "${CONFIG_BPF}" ]; then > ${RESOLVE_BTFIDS} vmlinux > fi > > +info SYSMAP System.map > +mksysmap vmlinux System.map > + > if [ -n "${CONFIG_BUILDTIME_TABLE_SORT}" ]; then > info SORTTAB vmlinux > if ! sorttable vmlinux; then > @@ -430,9 +433,6 @@ if [ -n "${CONFIG_BUILDTIME_TABLE_SORT}" ]; then > fi > fi > > -info SYSMAP System.map > -mksysmap vmlinux System.map > - > # step a (see comment above) > if [ -n "${CONFIG_KALLSYMS}" ]; then > mksysmap ${kallsyms_vmlinux} .tmp_System.map > diff --git a/scripts/sorttable.c b/scripts/sorttable.c > index 0ef3abfc4a51..11a595ca256b 100644 > --- a/scripts/sorttable.c > +++ b/scripts/sorttable.c > @@ -30,6 +30,8 @@ > #include <stdlib.h> > #include <string.h> > #include <unistd.h> > +#include <errno.h> > +#include <pthread.h> > > #include <tools/be_byteshift.h> > #include <tools/le_byteshift.h> > diff --git a/scripts/sorttable.h b/scripts/sorttable.h > index a2baa2fefb13..a7a5b8078954 100644 > --- a/scripts/sorttable.h > +++ b/scripts/sorttable.h > @@ -19,6 +19,9 @@ > > #undef extable_ent_size > #undef compare_extable > +#undef get_mcount_loc > +#undef sort_mcount_loc > +#undef elf_mcount_loc > #undef do_sort > #undef Elf_Addr > #undef Elf_Ehdr > @@ -41,6 +44,9 @@ > #ifdef SORTTABLE_64 > # define extable_ent_size 16 > # define compare_extable compare_extable_64 > +# define get_mcount_loc get_mcount_loc_64 > +# define sort_mcount_loc sort_mcount_loc_64 > +# define elf_mcount_loc elf_mcount_loc_64 > # define do_sort do_sort_64 > # define Elf_Addr Elf64_Addr > # define Elf_Ehdr Elf64_Ehdr > @@ -62,6 +68,9 @@ > #else > # define extable_ent_size 8 > # define compare_extable compare_extable_32 > +# define get_mcount_loc get_mcount_loc_32 > +# define sort_mcount_loc sort_mcount_loc_32 > +# define elf_mcount_loc elf_mcount_loc_32 > # define do_sort do_sort_32 > # define Elf_Addr Elf32_Addr > # define Elf_Ehdr Elf32_Ehdr > @@ -84,8 +93,6 @@ > > #if defined(SORTTABLE_64) && defined(UNWINDER_ORC_ENABLED) > /* ORC unwinder only support X86_64 */ > -#include <errno.h> > -#include <pthread.h> > #include <asm/orc_types.h> > > #define ERRSTR_MAXSZ 256 > @@ -191,7 +198,64 @@ static int compare_extable(const void *a, const void *b) > return 1; > return 0; > } > +#ifdef CONFIG_FUNCTION_TRACER > +struct elf_mcount_loc { > + Elf_Ehdr *ehdr; > + Elf_Shdr *init_data_sec; > + uint_t start_mcount_loc; > + uint_t stop_mcount_loc; > +}; > + > +/* Sort the addresses stored between __start_mcount_loc to __stop_mcount_loc in vmlinux */ > +static void *sort_mcount_loc(void *arg) > +{ > + struct elf_mcount_loc *emloc = (struct elf_mcount_loc *)arg; > + uint_t offset = emloc->start_mcount_loc - _r(&(emloc->init_data_sec)->sh_addr) > + + _r(&(emloc->init_data_sec)->sh_offset); > + uint_t count = emloc->stop_mcount_loc - emloc->start_mcount_loc; > + unsigned char *start_loc = (void *)emloc->ehdr + offset; > + > + qsort(start_loc, count/sizeof(uint_t), sizeof(uint_t), compare_extable); > + return NULL; > +} > + > +/* Get the address of __start_mcount_loc and __stop_mcount_loc in System.map */ > +static void get_mcount_loc(uint_t *_start, uint_t *_stop) > +{ > + FILE *file_start, *file_stop; > + char start_buff[20]; > + char stop_buff[20]; > + int len = 0; > + > + file_start = popen(" grep start_mcount System.map | awk '{print $1}' ", "r"); > + if (!file_start) { > + fprintf(stderr, "get start_mcount_loc error!"); > + return; > + } > + > + file_stop = popen(" grep stop_mcount System.map | awk '{print $1}' ", "r"); > + if (!file_stop) { > + fprintf(stderr, "get stop_mcount_loc error!"); > + pclose(file_start); > + return; > + } > + > + while (fgets(start_buff, sizeof(start_buff), file_start) != NULL) { > + len = strlen(start_buff); > + start_buff[len - 1] = '\0'; > + } > + *_start = strtoul(start_buff, NULL, 16); > + > + while (fgets(stop_buff, sizeof(stop_buff), file_stop) != NULL) { > + len = strlen(stop_buff); > + stop_buff[len - 1] = '\0'; > + } > + *_stop = strtoul(stop_buff, NULL, 16); > > + pclose(file_start); > + pclose(file_stop); > +} > +#endif > static int do_sort(Elf_Ehdr *ehdr, > char const *const fname, > table_sort_t custom_sort) > @@ -217,6 +281,12 @@ static int do_sort(Elf_Ehdr *ehdr, > int idx; > unsigned int shnum; > unsigned int shstrndx; > +#ifdef CONFIG_FUNCTION_TRACER > + struct elf_mcount_loc mstruct; > + uint_t _start_mcount_loc = 0; > + uint_t _stop_mcount_loc = 0; > + pthread_t mcount_sort_thread; > +#endif > #if defined(SORTTABLE_64) && defined(UNWINDER_ORC_ENABLED) > unsigned int orc_ip_size = 0; > unsigned int orc_size = 0; > @@ -253,6 +323,17 @@ static int do_sort(Elf_Ehdr *ehdr, > symtab_shndx = (Elf32_Word *)((const char *)ehdr + > _r(&s->sh_offset)); > > +#ifdef CONFIG_FUNCTION_TRACER > + /* locate the .init.data section in vmlinux */ > + if (!strcmp(secstrings + idx, ".init.data")) { > + get_mcount_loc(&_start_mcount_loc, &_stop_mcount_loc); > + mstruct.ehdr = ehdr; > + mstruct.init_data_sec = s; > + mstruct.start_mcount_loc = _start_mcount_loc; > + mstruct.stop_mcount_loc = _stop_mcount_loc; > + } > +#endif > + > #if defined(SORTTABLE_64) && defined(UNWINDER_ORC_ENABLED) > /* locate the ORC unwind tables */ > if (!strcmp(secstrings + idx, ".orc_unwind_ip")) { > @@ -294,6 +375,23 @@ static int do_sort(Elf_Ehdr *ehdr, > goto out; > } > #endif > + > +#ifdef CONFIG_FUNCTION_TRACER > + if (!mstruct.init_data_sec || !_start_mcount_loc || !_stop_mcount_loc) { > + fprintf(stderr, > + "incomplete mcount's sort in file: %s\n", > + fname); > + goto out; > + } > + > + /* create thread to sort mcount_loc concurrently */ > + if (pthread_create(&mcount_sort_thread, NULL, &sort_mcount_loc, &mstruct)) { > + fprintf(stderr, > + "pthread_create mcount_sort_thread failed '%s': %s\n", > + strerror(errno), fname); > + goto out; > + } > +#endif > if (!extab_sec) { > fprintf(stderr, "no __ex_table in file: %s\n", fname); > goto out; > @@ -376,5 +474,23 @@ static int do_sort(Elf_Ehdr *ehdr, > } > } > #endif > + > +#ifdef CONFIG_FUNCTION_TRACER > + if (mcount_sort_thread) { > + void *retval = NULL; > + /* wait for mcount sort done */ > + rc = pthread_join(mcount_sort_thread, &retval); > + if (rc) { > + fprintf(stderr, > + "pthread_join failed '%s': %s\n", > + strerror(errno), fname); > + } else if (retval) { > + rc = -1; > + fprintf(stderr, > + "failed to sort mcount '%s': %s\n", > + (char *)retval, fname); > + } > + } > +#endif > return rc; > }
[unhandled content-type:application/gzip] | |