2022-11-15 09:30:43

by Zhen Lei

[permalink] [raw]
Subject: [PATCH v9] kallsyms: Add self-test facility

Added test cases for basic functions and performance of functions
kallsyms_lookup_name(), kallsyms_on_each_symbol() and
kallsyms_on_each_match_symbol(). It also calculates the compression rate
of the kallsyms compression algorithm for the current symbol set.

The basic functions test begins by testing a set of symbols whose address
values are known. Then, traverse all symbol addresses and find the
corresponding symbol name based on the address. It's impossible to
determine whether these addresses are correct, but we can use the above
three functions along with the addresses to test each other. Due to the
traversal operation of kallsyms_on_each_symbol() is too slow, only 60
symbols can be tested in one second, so let it test on average once
every 128 symbols. The other two functions validate all symbols.

If the basic functions test is passed, print only performance test
results. If the test fails, print error information, but do not perform
subsequent performance tests.

Start self-test automatically after system startup if
CONFIG_KALLSYMS_SELFTEST=y.

Example of output content: (prefix 'kallsyms_selftest:' is omitted
start
---------------------------------------------------------
| nr_symbols | compressed size | original size | ratio(%) |
|---------------------------------------------------------|
| 107543 | 1357912 | 2407433 | 56.40 |
---------------------------------------------------------
kallsyms_lookup_name() looked up 107543 symbols
The time spent on each symbol is (ns): min=630, max=35295, avg=7353
kallsyms_on_each_symbol() traverse all: 11782628 ns
kallsyms_on_each_match_symbol() traverse all: 9261 ns
finish

Signed-off-by: Zhen Lei <[email protected]>
---
include/linux/kallsyms.h | 1 +
init/Kconfig | 13 +
kernel/Makefile | 1 +
kernel/kallsyms.c | 2 +-
kernel/kallsyms_selftest.c | 485 +++++++++++++++++++++++++++++++++++++
kernel/kallsyms_selftest.h | 13 +
6 files changed, 514 insertions(+), 1 deletion(-)
create mode 100644 kernel/kallsyms_selftest.c
create mode 100644 kernel/kallsyms_selftest.h

diff --git a/include/linux/kallsyms.h b/include/linux/kallsyms.h
index 0cd33be7142ad0d..0065209cc00424b 100644
--- a/include/linux/kallsyms.h
+++ b/include/linux/kallsyms.h
@@ -66,6 +66,7 @@ static inline void *dereference_symbol_descriptor(void *ptr)
}

#ifdef CONFIG_KALLSYMS
+unsigned long kallsyms_sym_address(int idx);
int kallsyms_on_each_symbol(int (*fn)(void *, const char *, struct module *,
unsigned long),
void *data);
diff --git a/init/Kconfig b/init/Kconfig
index abf65098f1b6bf1..c45935cd2f1f471 100644
--- a/init/Kconfig
+++ b/init/Kconfig
@@ -1723,6 +1723,19 @@ config KALLSYMS
symbolic stack backtraces. This increases the size of the kernel
somewhat, as all symbols have to be loaded into the kernel image.

+config KALLSYMS_SELFTEST
+ bool "Test the basic functions and performance of kallsyms"
+ depends on KALLSYMS
+ default n
+ help
+ Test the basic functions and performance of some interfaces, such as
+ kallsyms_lookup_name. It also calculates the compression rate of the
+ kallsyms compression algorithm for the current symbol set.
+
+ Start self-test automatically after system startup. Suggest executing
+ "dmesg | grep kallsyms_selftest" to collect test results. "finish" is
+ displayed in the last line, indicating that the test is complete.
+
config KALLSYMS_ALL
bool "Include all symbols in kallsyms"
depends on DEBUG_KERNEL && KALLSYMS
diff --git a/kernel/Makefile b/kernel/Makefile
index d754e0be1176df3..e7fc37a6806979f 100644
--- a/kernel/Makefile
+++ b/kernel/Makefile
@@ -69,6 +69,7 @@ endif
obj-$(CONFIG_UID16) += uid16.o
obj-$(CONFIG_MODULE_SIG_FORMAT) += module_signature.o
obj-$(CONFIG_KALLSYMS) += kallsyms.o
+obj-$(CONFIG_KALLSYMS_SELFTEST) += kallsyms_selftest.o
obj-$(CONFIG_BSD_PROCESS_ACCT) += acct.o
obj-$(CONFIG_CRASH_CORE) += crash_core.o
obj-$(CONFIG_KEXEC_CORE) += kexec_core.o
diff --git a/kernel/kallsyms.c b/kernel/kallsyms.c
index 0008ada2b135bef..83f499182c9aa31 100644
--- a/kernel/kallsyms.c
+++ b/kernel/kallsyms.c
@@ -146,7 +146,7 @@ static unsigned int get_symbol_offset(unsigned long pos)
return name - kallsyms_names;
}

-static unsigned long kallsyms_sym_address(int idx)
+unsigned long kallsyms_sym_address(int idx)
{
if (!IS_ENABLED(CONFIG_KALLSYMS_BASE_RELATIVE))
return kallsyms_addresses[idx];
diff --git a/kernel/kallsyms_selftest.c b/kernel/kallsyms_selftest.c
new file mode 100644
index 000000000000000..c1d73ace63abb98
--- /dev/null
+++ b/kernel/kallsyms_selftest.c
@@ -0,0 +1,485 @@
+// SPDX-License-Identifier: GPL-2.0-or-later
+/*
+ * Test the function and performance of kallsyms
+ *
+ * Copyright (C) Huawei Technologies Co., Ltd., 2022
+ *
+ * Authors: Zhen Lei <[email protected]> Huawei
+ */
+
+#define pr_fmt(fmt) "kallsyms_selftest: " fmt
+
+#include <linux/init.h>
+#include <linux/module.h>
+#include <linux/kallsyms.h>
+#include <linux/random.h>
+#include <linux/sched/clock.h>
+#include <linux/kthread.h>
+#include <linux/vmalloc.h>
+
+#include "kallsyms_internal.h"
+#include "kallsyms_selftest.h"
+
+
+#define MAX_NUM_OF_RECORDS 64
+
+struct test_stat {
+ int min;
+ int max;
+ int save_cnt;
+ int real_cnt;
+ int perf;
+ u64 sum;
+ char *name;
+ unsigned long addr;
+ unsigned long addrs[MAX_NUM_OF_RECORDS];
+};
+
+struct test_item {
+ char *name;
+ unsigned long addr;
+};
+
+#define ITEM_FUNC(s) \
+ { \
+ .name = #s, \
+ .addr = (unsigned long)s, \
+ }
+
+#define ITEM_DATA(s) \
+ { \
+ .name = #s, \
+ .addr = (unsigned long)&s, \
+ }
+
+
+static int kallsyms_test_var_bss_static;
+static int kallsyms_test_var_data_static = 1;
+int kallsyms_test_var_bss;
+int kallsyms_test_var_data = 1;
+
+static int kallsyms_test_func_static(void)
+{
+ kallsyms_test_var_bss_static++;
+ kallsyms_test_var_data_static++;
+
+ return 0;
+}
+
+int kallsyms_test_func(void)
+{
+ return kallsyms_test_func_static();
+}
+
+__weak int kallsyms_test_func_weak(void)
+{
+ kallsyms_test_var_bss++;
+ kallsyms_test_var_data++;
+ return 0;
+}
+
+static struct test_item test_items[] = {
+ ITEM_FUNC(kallsyms_test_func_static),
+ ITEM_FUNC(kallsyms_test_func),
+ ITEM_FUNC(kallsyms_test_func_weak),
+ ITEM_FUNC(vmalloc),
+ ITEM_FUNC(vfree),
+#ifdef CONFIG_KALLSYMS_ALL
+ ITEM_DATA(kallsyms_test_var_bss_static),
+ ITEM_DATA(kallsyms_test_var_data_static),
+ ITEM_DATA(kallsyms_test_var_bss),
+ ITEM_DATA(kallsyms_test_var_data),
+ ITEM_DATA(vmap_area_list),
+#endif
+};
+
+static char stub_name[KSYM_NAME_LEN];
+
+static int stat_symbol_len(void *data, const char *name, struct module *mod, unsigned long addr)
+{
+ *(u32 *)data += strlen(name);
+
+ return 0;
+}
+
+static void test_kallsyms_compression_ratio(void)
+{
+ u32 pos, off, len, num;
+ u32 ratio, total_size, total_len = 0;
+
+ kallsyms_on_each_symbol(stat_symbol_len, &total_len);
+
+ /*
+ * A symbol name cannot start with a number. This stub name helps us
+ * traverse the entire symbol table without finding a match. It's used
+ * for subsequent performance tests, and its length is the average
+ * length of all symbol names.
+ */
+ memset(stub_name, '4', sizeof(stub_name));
+ pos = total_len / kallsyms_num_syms;
+ stub_name[pos] = 0;
+
+ pos = 0;
+ num = 0;
+ off = 0;
+ while (pos < kallsyms_num_syms) {
+ len = kallsyms_names[off];
+ num++;
+ off++;
+ pos++;
+ if ((len & 0x80) != 0) {
+ len = (len & 0x7f) | (kallsyms_names[off] << 7);
+ num++;
+ off++;
+ }
+ off += len;
+ };
+
+ /*
+ * 1. The length fields is not counted
+ * 2. The memory occupied by array kallsyms_token_table[] and
+ * kallsyms_token_index[] needs to be counted.
+ */
+ total_size = off - num;
+ pos = kallsyms_token_index[0xff];
+ total_size += pos + strlen(&kallsyms_token_table[pos]) + 1;
+ total_size += 0x100 * sizeof(u16);
+
+ pr_info(" ---------------------------------------------------------\n");
+ pr_info("| nr_symbols | compressed size | original size | ratio(%%) |\n");
+ pr_info("|---------------------------------------------------------|\n");
+ ratio = (u32)div_u64(10000ULL * total_size, total_len);
+ pr_info("| %10d | %10d | %10d | %2d.%-2d |\n",
+ kallsyms_num_syms, total_size, total_len, ratio / 100, ratio % 100);
+ pr_info(" ---------------------------------------------------------\n");
+}
+
+static int lookup_name(void *data, const char *name, struct module *mod, unsigned long addr)
+{
+ u64 t0, t1, t;
+ unsigned long flags;
+ struct test_stat *stat = (struct test_stat *)data;
+
+ local_irq_save(flags);
+ t0 = sched_clock();
+ (void)kallsyms_lookup_name(name);
+ t1 = sched_clock();
+ local_irq_restore(flags);
+
+ t = t1 - t0;
+ if (t < stat->min)
+ stat->min = t;
+
+ if (t > stat->max)
+ stat->max = t;
+
+ stat->real_cnt++;
+ stat->sum += t;
+
+ return 0;
+}
+
+static void test_perf_kallsyms_lookup_name(void)
+{
+ struct test_stat stat;
+
+ memset(&stat, 0, sizeof(stat));
+ stat.min = INT_MAX;
+ kallsyms_on_each_symbol(lookup_name, &stat);
+ pr_info("kallsyms_lookup_name() looked up %d symbols\n", stat.real_cnt);
+ pr_info("The time spent on each symbol is (ns): min=%d, max=%d, avg=%lld\n",
+ stat.min, stat.max, div_u64(stat.sum, stat.real_cnt));
+}
+
+static bool match_cleanup_name(const char *s, const char *name)
+{
+ char *p;
+ int len;
+
+ if (!IS_ENABLED(CONFIG_LTO_CLANG))
+ return false;
+
+ p = strchr(s, '.');
+ if (!p)
+ return false;
+
+ len = strlen(name);
+ if (p - s != len)
+ return false;
+
+ return !strncmp(s, name, len);
+}
+
+static int find_symbol(void *data, const char *name, struct module *mod, unsigned long addr)
+{
+ struct test_stat *stat = (struct test_stat *)data;
+
+ if (strcmp(name, stat->name) == 0 ||
+ (!stat->perf && match_cleanup_name(name, stat->name))) {
+ stat->real_cnt++;
+ stat->addr = addr;
+
+ if (stat->save_cnt < MAX_NUM_OF_RECORDS) {
+ stat->addrs[stat->save_cnt] = addr;
+ stat->save_cnt++;
+ }
+
+ if (stat->real_cnt == stat->max)
+ return 1;
+ }
+
+ return 0;
+}
+
+static void test_perf_kallsyms_on_each_symbol(void)
+{
+ u64 t0, t1;
+ unsigned long flags;
+ struct test_stat stat;
+
+ memset(&stat, 0, sizeof(stat));
+ stat.max = INT_MAX;
+ stat.name = stub_name;
+ stat.perf = 1;
+ local_irq_save(flags);
+ t0 = sched_clock();
+ kallsyms_on_each_symbol(find_symbol, &stat);
+ t1 = sched_clock();
+ local_irq_restore(flags);
+ pr_info("kallsyms_on_each_symbol() traverse all: %lld ns\n", t1 - t0);
+}
+
+static int match_symbol(void *data, unsigned long addr)
+{
+ struct test_stat *stat = (struct test_stat *)data;
+
+ stat->real_cnt++;
+ stat->addr = addr;
+
+ if (stat->save_cnt < MAX_NUM_OF_RECORDS) {
+ stat->addrs[stat->save_cnt] = addr;
+ stat->save_cnt++;
+ }
+
+ if (stat->real_cnt == stat->max)
+ return 1;
+
+ return 0;
+}
+
+static void test_perf_kallsyms_on_each_match_symbol(void)
+{
+ u64 t0, t1;
+ unsigned long flags;
+ struct test_stat stat;
+
+ memset(&stat, 0, sizeof(stat));
+ stat.max = INT_MAX;
+ stat.name = stub_name;
+ local_irq_save(flags);
+ t0 = sched_clock();
+ kallsyms_on_each_match_symbol(match_symbol, stat.name, &stat);
+ t1 = sched_clock();
+ local_irq_restore(flags);
+ pr_info("kallsyms_on_each_match_symbol() traverse all: %lld ns\n", t1 - t0);
+}
+
+static int test_kallsyms_basic_function(void)
+{
+ int i, j, ret;
+ int next = 0, nr_failed = 0;
+ char *prefix;
+ unsigned short rand;
+ unsigned long addr, lookup_addr;
+ char namebuf[KSYM_NAME_LEN];
+ struct test_stat *stat, *stat2;
+
+ stat = kmalloc(sizeof(*stat) * 2, GFP_KERNEL);
+ if (!stat)
+ return -ENOMEM;
+ stat2 = stat + 1;
+
+ prefix = "kallsyms_lookup_name() for";
+ for (i = 0; i < ARRAY_SIZE(test_items); i++) {
+ addr = kallsyms_lookup_name(test_items[i].name);
+ if (addr != test_items[i].addr) {
+ nr_failed++;
+ pr_info("%s %s failed: addr=%lx, expect %lx\n",
+ prefix, test_items[i].name, addr, test_items[i].addr);
+ }
+ }
+
+ prefix = "kallsyms_on_each_symbol() for";
+ for (i = 0; i < ARRAY_SIZE(test_items); i++) {
+ memset(stat, 0, sizeof(*stat));
+ stat->max = INT_MAX;
+ stat->name = test_items[i].name;
+ kallsyms_on_each_symbol(find_symbol, stat);
+ if (stat->addr != test_items[i].addr || stat->real_cnt != 1) {
+ nr_failed++;
+ pr_info("%s %s failed: count=%d, addr=%lx, expect %lx\n",
+ prefix, test_items[i].name,
+ stat->real_cnt, stat->addr, test_items[i].addr);
+ }
+ }
+
+ prefix = "kallsyms_on_each_match_symbol() for";
+ for (i = 0; i < ARRAY_SIZE(test_items); i++) {
+ memset(stat, 0, sizeof(*stat));
+ stat->max = INT_MAX;
+ stat->name = test_items[i].name;
+ kallsyms_on_each_match_symbol(match_symbol, test_items[i].name, stat);
+ if (stat->addr != test_items[i].addr || stat->real_cnt != 1) {
+ nr_failed++;
+ pr_info("%s %s failed: count=%d, addr=%lx, expect %lx\n",
+ prefix, test_items[i].name,
+ stat->real_cnt, stat->addr, test_items[i].addr);
+ }
+ }
+
+ if (nr_failed) {
+ kfree(stat);
+ return -ESRCH;
+ }
+
+ for (i = 0; i < kallsyms_num_syms; i++) {
+ addr = kallsyms_sym_address(i);
+ if (!is_ksym_addr(addr))
+ continue;
+
+ ret = lookup_symbol_name(addr, namebuf);
+ if (unlikely(ret)) {
+ namebuf[0] = 0;
+ goto failed;
+ }
+
+ /*
+ * The first '.' may be the initial letter, in which case the
+ * entire symbol name will be truncated to an empty string in
+ * cleanup_symbol_name(). Do not test these symbols.
+ *
+ * For example:
+ * cat /proc/kallsyms | awk '{print $3}' | grep -E "^\." | head
+ * .E_read_words
+ * .E_leading_bytes
+ * .E_trailing_bytes
+ * .E_write_words
+ * .E_copy
+ * .str.292.llvm.12122243386960820698
+ * .str.24.llvm.12122243386960820698
+ * .str.29.llvm.12122243386960820698
+ * .str.75.llvm.12122243386960820698
+ * .str.99.llvm.12122243386960820698
+ */
+ if (IS_ENABLED(CONFIG_LTO_CLANG) && !namebuf[0])
+ continue;
+
+ lookup_addr = kallsyms_lookup_name(namebuf);
+
+ memset(stat, 0, sizeof(*stat));
+ stat->max = INT_MAX;
+ kallsyms_on_each_match_symbol(match_symbol, namebuf, stat);
+
+ /*
+ * kallsyms_on_each_symbol() is too slow, randomly select some
+ * symbols for test.
+ */
+ if (i >= next) {
+ memset(stat2, 0, sizeof(*stat2));
+ stat2->max = INT_MAX;
+ stat2->name = namebuf;
+ kallsyms_on_each_symbol(find_symbol, stat2);
+
+ /*
+ * kallsyms_on_each_symbol() and kallsyms_on_each_match_symbol()
+ * need to get the same traversal result.
+ */
+ if (stat->addr != stat2->addr ||
+ stat->real_cnt != stat2->real_cnt ||
+ memcmp(stat->addrs, stat2->addrs,
+ stat->save_cnt * sizeof(stat->addrs[0])))
+ goto failed;
+
+ /*
+ * The average of random increments is 128, that is, one of
+ * them is tested every 128 symbols.
+ */
+ get_random_bytes(&rand, sizeof(rand));
+ next = i + (rand & 0xff) + 1;
+ }
+
+ /* Need to be found at least once */
+ if (!stat->real_cnt)
+ goto failed;
+
+ /*
+ * kallsyms_lookup_name() returns the address of the first
+ * symbol found and cannot be NULL.
+ */
+ if (!lookup_addr || lookup_addr != stat->addrs[0])
+ goto failed;
+
+ /*
+ * If the addresses of all matching symbols are recorded, the
+ * target address needs to be exist.
+ */
+ if (stat->real_cnt <= MAX_NUM_OF_RECORDS) {
+ for (j = 0; j < stat->save_cnt; j++) {
+ if (stat->addrs[j] == addr)
+ break;
+ }
+
+ if (j == stat->save_cnt)
+ goto failed;
+ }
+ }
+
+ kfree(stat);
+
+ return 0;
+
+failed:
+ pr_info("Test for %dth symbol failed: (%s) addr=%lx", i, namebuf, addr);
+ kfree(stat);
+ return -ESRCH;
+}
+
+static int test_entry(void *p)
+{
+ int ret;
+
+ do {
+ schedule_timeout(5 * HZ);
+ } while (system_state != SYSTEM_RUNNING);
+
+ pr_info("start\n");
+ ret = test_kallsyms_basic_function();
+ if (ret) {
+ pr_info("abort\n");
+ return 0;
+ }
+
+ test_kallsyms_compression_ratio();
+ test_perf_kallsyms_lookup_name();
+ test_perf_kallsyms_on_each_symbol();
+ test_perf_kallsyms_on_each_match_symbol();
+ pr_info("finish\n");
+
+ return 0;
+}
+
+static int __init kallsyms_test_init(void)
+{
+ struct task_struct *t;
+
+ t = kthread_create(test_entry, NULL, "kallsyms_test");
+ if (IS_ERR(t)) {
+ pr_info("Create kallsyms selftest task failed\n");
+ return PTR_ERR(t);
+ }
+ kthread_bind(t, 0);
+ wake_up_process(t);
+
+ return 0;
+}
+late_initcall(kallsyms_test_init);
diff --git a/kernel/kallsyms_selftest.h b/kernel/kallsyms_selftest.h
new file mode 100644
index 000000000000000..c0ca548e2a22599
--- /dev/null
+++ b/kernel/kallsyms_selftest.h
@@ -0,0 +1,13 @@
+/* SPDX-License-Identifier: GPL-2.0-or-later */
+#ifndef LINUX_KALLSYMS_SELFTEST_H_
+#define LINUX_KALLSYMS_SELFTEST_H_
+
+#include <linux/types.h>
+
+extern int kallsyms_test_var_bss;
+extern int kallsyms_test_var_data;
+
+extern int kallsyms_test_func(void);
+extern int kallsyms_test_func_weak(void);
+
+#endif // LINUX_KALLSYMS_SELFTEST_H_
--
2.25.1



2022-11-15 09:35:18

by Luis Chamberlain

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Tue, Nov 15, 2022 at 04:33:48PM +0800, Zhen Lei wrote:
> Added test cases for basic functions and performance of functions
> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> of the kallsyms compression algorithm for the current symbol set.
>
> The basic functions test begins by testing a set of symbols whose address
> values are known. Then, traverse all symbol addresses and find the
> corresponding symbol name based on the address. It's impossible to
> determine whether these addresses are correct, but we can use the above
> three functions along with the addresses to test each other. Due to the
> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> symbols can be tested in one second, so let it test on average once
> every 128 symbols. The other two functions validate all symbols.
>
> If the basic functions test is passed, print only performance test
> results. If the test fails, print error information, but do not perform
> subsequent performance tests.
>
> Start self-test automatically after system startup if
> CONFIG_KALLSYMS_SELFTEST=y.
>
> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> start
> ---------------------------------------------------------
> | nr_symbols | compressed size | original size | ratio(%) |
> |---------------------------------------------------------|
> | 107543 | 1357912 | 2407433 | 56.40 |
> ---------------------------------------------------------
> kallsyms_lookup_name() looked up 107543 symbols
> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> kallsyms_on_each_symbol() traverse all: 11782628 ns
> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> finish
>
> Signed-off-by: Zhen Lei <[email protected]>

Thanks! Queued onto module-next.

Luis

2022-12-15 09:15:03

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
> Added test cases for basic functions and performance of functions
> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> of the kallsyms compression algorithm for the current symbol set.
>
> The basic functions test begins by testing a set of symbols whose address
> values are known. Then, traverse all symbol addresses and find the
> corresponding symbol name based on the address. It's impossible to
> determine whether these addresses are correct, but we can use the above
> three functions along with the addresses to test each other. Due to the
> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> symbols can be tested in one second, so let it test on average once
> every 128 symbols. The other two functions validate all symbols.
>
> If the basic functions test is passed, print only performance test
> results. If the test fails, print error information, but do not perform
> subsequent performance tests.
>
> Start self-test automatically after system startup if
> CONFIG_KALLSYMS_SELFTEST=y.
>
> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> start
> ---------------------------------------------------------
> | nr_symbols | compressed size | original size | ratio(%) |
> |---------------------------------------------------------|
> | 107543 | 1357912 | 2407433 | 56.40 |
> ---------------------------------------------------------
> kallsyms_lookup_name() looked up 107543 symbols
> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> kallsyms_on_each_symbol() traverse all: 11782628 ns
> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> finish
>
> Signed-off-by: Zhen Lei <[email protected]>

Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
Add self-test facility") in linus/master.

I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
but it failed:

start
kallsyms_lookup_name() for kallsyms_test_func_static failed:
addr=0, expect 60ab0
kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
expect 60ac2
kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
kallsyms_on_each_match_symbol() for kallsyms_test_func_static
failed: count=0, addr=0, expect 60ab0
kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
count=0, addr=0, expect 60ac0
kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
failed: count=0, addr=0, expect 60ac2
kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
addr=0, expect c272a
kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
expect c2142
abort

Given all addresses are zero, it looks like some required functionality
or config option is missing.

$ grep SYM .config
CONFIG_KALLSYMS=y
CONFIG_KALLSYMS_SELFTEST=y
CONFIG_KALLSYMS_BASE_RELATIVE=y
# CONFIG_ASYMMETRIC_KEY_TYPE is not set
CONFIG_SYMBOLIC_ERRNAME=y
# CONFIG_STRIP_ASM_SYMS is not set
CONFIG_KALLSYMS_SELFTEST

Do you have a clue?

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-15 09:35:49

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/15 16:50, Geert Uytterhoeven wrote:
> Hi Zhen,
>
> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
>> Added test cases for basic functions and performance of functions
>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
>> of the kallsyms compression algorithm for the current symbol set.
>>
>> The basic functions test begins by testing a set of symbols whose address
>> values are known. Then, traverse all symbol addresses and find the
>> corresponding symbol name based on the address. It's impossible to
>> determine whether these addresses are correct, but we can use the above
>> three functions along with the addresses to test each other. Due to the
>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
>> symbols can be tested in one second, so let it test on average once
>> every 128 symbols. The other two functions validate all symbols.
>>
>> If the basic functions test is passed, print only performance test
>> results. If the test fails, print error information, but do not perform
>> subsequent performance tests.
>>
>> Start self-test automatically after system startup if
>> CONFIG_KALLSYMS_SELFTEST=y.
>>
>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
>> start
>> ---------------------------------------------------------
>> | nr_symbols | compressed size | original size | ratio(%) |
>> |---------------------------------------------------------|
>> | 107543 | 1357912 | 2407433 | 56.40 |
>> ---------------------------------------------------------
>> kallsyms_lookup_name() looked up 107543 symbols
>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
>> kallsyms_on_each_symbol() traverse all: 11782628 ns
>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
>> finish
>>
>> Signed-off-by: Zhen Lei <[email protected]>
>
> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
> Add self-test facility") in linus/master.
>
> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
> but it failed:
>
> start
> kallsyms_lookup_name() for kallsyms_test_func_static failed:
> addr=0, expect 60ab0
> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
> expect 60ac2
> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> failed: count=0, addr=0, expect 60ab0
> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> count=0, addr=0, expect 60ac0
> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> failed: count=0, addr=0, expect 60ac2
> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
> addr=0, expect c272a
> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
> expect c2142
> abort
>
> Given all addresses are zero, it looks like some required functionality
> or config option is missing.
>
> $ grep SYM .config
> CONFIG_KALLSYMS=y
> CONFIG_KALLSYMS_SELFTEST=y
> CONFIG_KALLSYMS_BASE_RELATIVE=y
> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
> CONFIG_SYMBOLIC_ERRNAME=y
> # CONFIG_STRIP_ASM_SYMS is not set
> CONFIG_KALLSYMS_SELFTEST
>
> Do you have a clue?

cat /proc/kallsyms | grep kallsyms_test_func
Let's see if the compiler-generated symbols have some special suffixes.


>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
> -- Linus Torvalds
>
> .
>

--
Regards,
Zhen Lei

2022-12-15 10:22:38

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
> > On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
> >> Added test cases for basic functions and performance of functions
> >> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> >> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> >> of the kallsyms compression algorithm for the current symbol set.
> >>
> >> The basic functions test begins by testing a set of symbols whose address
> >> values are known. Then, traverse all symbol addresses and find the
> >> corresponding symbol name based on the address. It's impossible to
> >> determine whether these addresses are correct, but we can use the above
> >> three functions along with the addresses to test each other. Due to the
> >> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> >> symbols can be tested in one second, so let it test on average once
> >> every 128 symbols. The other two functions validate all symbols.
> >>
> >> If the basic functions test is passed, print only performance test
> >> results. If the test fails, print error information, but do not perform
> >> subsequent performance tests.
> >>
> >> Start self-test automatically after system startup if
> >> CONFIG_KALLSYMS_SELFTEST=y.
> >>
> >> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> >> start
> >> ---------------------------------------------------------
> >> | nr_symbols | compressed size | original size | ratio(%) |
> >> |---------------------------------------------------------|
> >> | 107543 | 1357912 | 2407433 | 56.40 |
> >> ---------------------------------------------------------
> >> kallsyms_lookup_name() looked up 107543 symbols
> >> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> >> kallsyms_on_each_symbol() traverse all: 11782628 ns
> >> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> >> finish
> >>
> >> Signed-off-by: Zhen Lei <[email protected]>
> >
> > Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
> > Add self-test facility") in linus/master.
> >
> > I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
> > but it failed:
> >
> > start
> > kallsyms_lookup_name() for kallsyms_test_func_static failed:
> > addr=0, expect 60ab0
> > kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
> > kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
> > expect 60ac2
> > kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
> > kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
> > kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> > failed: count=0, addr=0, expect 60ab0
> > kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> > count=0, addr=0, expect 60ac0
> > kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> > failed: count=0, addr=0, expect 60ac2
> > kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
> > addr=0, expect c272a
> > kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
> > expect c2142
> > abort
> >
> > Given all addresses are zero, it looks like some required functionality
> > or config option is missing.
> >
> > $ grep SYM .config
> > CONFIG_KALLSYMS=y
> > CONFIG_KALLSYMS_SELFTEST=y
> > CONFIG_KALLSYMS_BASE_RELATIVE=y
> > # CONFIG_ASYMMETRIC_KEY_TYPE is not set
> > CONFIG_SYMBOLIC_ERRNAME=y
> > # CONFIG_STRIP_ASM_SYMS is not set
> > CONFIG_KALLSYMS_SELFTEST
> >
> > Do you have a clue?
>
> cat /proc/kallsyms | grep kallsyms_test_func
> Let's see if the compiler-generated symbols have some special suffixes.

Thanks, looks normal to me:

atari:~# cat /proc/kallsyms | grep kallsyms_test_func
00060ab0 t kallsyms_test_func_static
00060ac0 T kallsyms_test_func
00060ac2 W kallsyms_test_func_weak
atari:~#

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-15 12:42:51

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/15 17:39, Geert Uytterhoeven wrote:
> Hi Zhen,
>
> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
> <[email protected]> wrote:
>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
>>>> Added test cases for basic functions and performance of functions
>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
>>>> of the kallsyms compression algorithm for the current symbol set.
>>>>
>>>> The basic functions test begins by testing a set of symbols whose address
>>>> values are known. Then, traverse all symbol addresses and find the
>>>> corresponding symbol name based on the address. It's impossible to
>>>> determine whether these addresses are correct, but we can use the above
>>>> three functions along with the addresses to test each other. Due to the
>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
>>>> symbols can be tested in one second, so let it test on average once
>>>> every 128 symbols. The other two functions validate all symbols.
>>>>
>>>> If the basic functions test is passed, print only performance test
>>>> results. If the test fails, print error information, but do not perform
>>>> subsequent performance tests.
>>>>
>>>> Start self-test automatically after system startup if
>>>> CONFIG_KALLSYMS_SELFTEST=y.
>>>>
>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
>>>> start
>>>> ---------------------------------------------------------
>>>> | nr_symbols | compressed size | original size | ratio(%) |
>>>> |---------------------------------------------------------|
>>>> | 107543 | 1357912 | 2407433 | 56.40 |
>>>> ---------------------------------------------------------
>>>> kallsyms_lookup_name() looked up 107543 symbols
>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
>>>> finish
>>>>
>>>> Signed-off-by: Zhen Lei <[email protected]>
>>>
>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
>>> Add self-test facility") in linus/master.
>>>
>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
>>> but it failed:
>>>
>>> start
>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
>>> addr=0, expect 60ab0
>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
>>> expect 60ac2
>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
>>> failed: count=0, addr=0, expect 60ab0
>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
>>> count=0, addr=0, expect 60ac0
>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
>>> failed: count=0, addr=0, expect 60ac2
>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
>>> addr=0, expect c272a
>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
>>> expect c2142
>>> abort
>>>
>>> Given all addresses are zero, it looks like some required functionality
>>> or config option is missing.
>>>
>>> $ grep SYM .config
>>> CONFIG_KALLSYMS=y
>>> CONFIG_KALLSYMS_SELFTEST=y
>>> CONFIG_KALLSYMS_BASE_RELATIVE=y
>>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
>>> CONFIG_SYMBOLIC_ERRNAME=y
>>> # CONFIG_STRIP_ASM_SYMS is not set
>>> CONFIG_KALLSYMS_SELFTEST
>>>
>>> Do you have a clue?
>>
>> cat /proc/kallsyms | grep kallsyms_test_func
>> Let's see if the compiler-generated symbols have some special suffixes.
>
> Thanks, looks normal to me:
>
> atari:~# cat /proc/kallsyms | grep kallsyms_test_func
> 00060ab0 t kallsyms_test_func_static
> 00060ac0 T kallsyms_test_func
> 00060ac2 W kallsyms_test_func_weak
> atari:~#

It's incredible. I don't have a m68k environment and I'm trying to build a qemu
environment. If you're in a hurry and willing, you can apply the debugging patch
in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
the output information.

>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
> -- Linus Torvalds
>
> .
>

--
Regards,
Zhen Lei


Attachments:
0001-kallsyms-debug-m68k.patch (2.44 kB)

2022-12-15 13:38:12

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

CC Jason

On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
> > On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
> > <[email protected]> wrote:
> >> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
> >>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
> >>>> Added test cases for basic functions and performance of functions
> >>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> >>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> >>>> of the kallsyms compression algorithm for the current symbol set.
> >>>>
> >>>> The basic functions test begins by testing a set of symbols whose address
> >>>> values are known. Then, traverse all symbol addresses and find the
> >>>> corresponding symbol name based on the address. It's impossible to
> >>>> determine whether these addresses are correct, but we can use the above
> >>>> three functions along with the addresses to test each other. Due to the
> >>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> >>>> symbols can be tested in one second, so let it test on average once
> >>>> every 128 symbols. The other two functions validate all symbols.
> >>>>
> >>>> If the basic functions test is passed, print only performance test
> >>>> results. If the test fails, print error information, but do not perform
> >>>> subsequent performance tests.
> >>>>
> >>>> Start self-test automatically after system startup if
> >>>> CONFIG_KALLSYMS_SELFTEST=y.
> >>>>
> >>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> >>>> start
> >>>> ---------------------------------------------------------
> >>>> | nr_symbols | compressed size | original size | ratio(%) |
> >>>> |---------------------------------------------------------|
> >>>> | 107543 | 1357912 | 2407433 | 56.40 |
> >>>> ---------------------------------------------------------
> >>>> kallsyms_lookup_name() looked up 107543 symbols
> >>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> >>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
> >>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> >>>> finish
> >>>>
> >>>> Signed-off-by: Zhen Lei <[email protected]>
> >>>
> >>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
> >>> Add self-test facility") in linus/master.
> >>>
> >>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
> >>> but it failed:
> >>>
> >>> start
> >>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
> >>> addr=0, expect 60ab0
> >>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
> >>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
> >>> expect 60ac2
> >>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
> >>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
> >>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> >>> failed: count=0, addr=0, expect 60ab0
> >>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> >>> count=0, addr=0, expect 60ac0
> >>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> >>> failed: count=0, addr=0, expect 60ac2
> >>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
> >>> addr=0, expect c272a
> >>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
> >>> expect c2142
> >>> abort
> >>>
> >>> Given all addresses are zero, it looks like some required functionality
> >>> or config option is missing.
> >>>
> >>> $ grep SYM .config
> >>> CONFIG_KALLSYMS=y
> >>> CONFIG_KALLSYMS_SELFTEST=y
> >>> CONFIG_KALLSYMS_BASE_RELATIVE=y
> >>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
> >>> CONFIG_SYMBOLIC_ERRNAME=y
> >>> # CONFIG_STRIP_ASM_SYMS is not set
> >>> CONFIG_KALLSYMS_SELFTEST
> >>>
> >>> Do you have a clue?
> >>
> >> cat /proc/kallsyms | grep kallsyms_test_func
> >> Let's see if the compiler-generated symbols have some special suffixes.
> >
> > Thanks, looks normal to me:
> >
> > atari:~# cat /proc/kallsyms | grep kallsyms_test_func
> > 00060ab0 t kallsyms_test_func_static
> > 00060ac0 T kallsyms_test_func
> > 00060ac2 W kallsyms_test_func_weak
> > atari:~#
>
> It's incredible. I don't have a m68k environment and I'm trying to build a qemu
> environment. If you're in a hurry and willing, you can apply the debugging patch
> in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
> the output information.

Still fails:

tst: found kallsyms_test_func at index=12845
tst: [12533] = kallsyms_test_func, seq=17370, offset=191223
tst: [18800] = kallsyms_test_func, seq=23193, offset=259263
tst: [21934] = kallsyms_test_func, seq=2527, offset=22331
tst: [23501] = kallsyms_test_func, seq=11792, offset=126366
tst: [24284] = kallsyms_test_func, seq=8427, offset=87395
tst: [24676] = kallsyms_test_func, seq=21896, offset=243536
tst: [24872] = kallsyms_test_func, seq=22571, offset=251856
tst: [24970] = kallsyms_test_func, seq=23264, offset=260074
tst: [25019] = kallsyms_test_func, seq=9003, offset=93752
tst: [25043] = kallsyms_test_func, seq=14324, offset=155117
tst: [25055] = kallsyms_test_func, seq=5942, offset=62266
tst: [25061] = kallsyms_test_func, seq=14347, offset=155467
tst: [25064] = kallsyms_test_func, seq=14350, offset=155512
tst: [25066] = kallsyms_test_func, seq=14346, offset=155457
tst: [25067] = kallsyms_test_func, seq=14354, offset=155565

However, the binary search sequence looks very suspicious.
After investigation, it turns out compare_symbol_name() and strcmp()
always return positive numbers.

Looks like commit 3bc753c06dd02a35 ("kbuild: treat char as always
unsigned") is to blame.

Changing:

--- a/arch/m68k/include/asm/string.h
+++ b/arch/m68k/include/asm/string.h
@@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
char *src, size_t n)
#define __HAVE_ARCH_STRCMP
static inline int strcmp(const char *cs, const char *ct)
{
- char res;
+ signed char res;

asm ("\n"
"1: move.b (%0)+,%2\n" /* get *cs */

fixes strcmp, but the test still fails:

tst: kallsyms_lookup_names() is OK, name=kallsyms_test_func, i=0
kallsyms_selftest: kallsyms_lookup_name() for
kallsyms_test_func_static failed: addr=8e1c, expect 60cd4
kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func
failed: addr=8e1c, expect 60ce4
kallsyms_selftest: kallsyms_lookup_name() for
kallsyms_test_func_weak failed: addr=8e1c, expect 60ce6
kallsyms_selftest: kallsyms_lookup_name() for vmalloc failed:
addr=8e1c, expect c2946
kallsyms_selftest: kallsyms_lookup_name() for vfree failed:
addr=8e1c, expect c235e
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func_static failed: count=25068, addr=1f3d3c, expect
60cd4
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func failed: count=25068, addr=1f3d3c, expect 60ce4
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func_weak failed: count=25068, addr=1f3d3c, expect 60ce6
kallsyms_selftest: kallsyms_on_each_match_symbol() for vmalloc
failed: count=25068, addr=1f3d3c, expect c2946
kallsyms_selftest: kallsyms_on_each_match_symbol() for vfree
failed: count=25068, addr=1f3d3c, expect c235e
kallsyms_selftest: abort

Dropping -funsigned-char doesn't improve upon that...

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-15 14:46:19

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/15 21:24, Geert Uytterhoeven wrote:
> Hi Zhen,
>
> CC Jason
>
> On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
> <[email protected]> wrote:
>> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
>>> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
>>> <[email protected]> wrote:
>>>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
>>>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
>>>>>> Added test cases for basic functions and performance of functions
>>>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
>>>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
>>>>>> of the kallsyms compression algorithm for the current symbol set.
>>>>>>
>>>>>> The basic functions test begins by testing a set of symbols whose address
>>>>>> values are known. Then, traverse all symbol addresses and find the
>>>>>> corresponding symbol name based on the address. It's impossible to
>>>>>> determine whether these addresses are correct, but we can use the above
>>>>>> three functions along with the addresses to test each other. Due to the
>>>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
>>>>>> symbols can be tested in one second, so let it test on average once
>>>>>> every 128 symbols. The other two functions validate all symbols.
>>>>>>
>>>>>> If the basic functions test is passed, print only performance test
>>>>>> results. If the test fails, print error information, but do not perform
>>>>>> subsequent performance tests.
>>>>>>
>>>>>> Start self-test automatically after system startup if
>>>>>> CONFIG_KALLSYMS_SELFTEST=y.
>>>>>>
>>>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
>>>>>> start
>>>>>> ---------------------------------------------------------
>>>>>> | nr_symbols | compressed size | original size | ratio(%) |
>>>>>> |---------------------------------------------------------|
>>>>>> | 107543 | 1357912 | 2407433 | 56.40 |
>>>>>> ---------------------------------------------------------
>>>>>> kallsyms_lookup_name() looked up 107543 symbols
>>>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
>>>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
>>>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
>>>>>> finish
>>>>>>
>>>>>> Signed-off-by: Zhen Lei <[email protected]>
>>>>>
>>>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
>>>>> Add self-test facility") in linus/master.
>>>>>
>>>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
>>>>> but it failed:
>>>>>
>>>>> start
>>>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
>>>>> addr=0, expect 60ab0
>>>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
>>>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
>>>>> expect 60ac2
>>>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
>>>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
>>>>> failed: count=0, addr=0, expect 60ab0
>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
>>>>> count=0, addr=0, expect 60ac0
>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
>>>>> failed: count=0, addr=0, expect 60ac2
>>>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
>>>>> addr=0, expect c272a
>>>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
>>>>> expect c2142
>>>>> abort
>>>>>
>>>>> Given all addresses are zero, it looks like some required functionality
>>>>> or config option is missing.
>>>>>
>>>>> $ grep SYM .config
>>>>> CONFIG_KALLSYMS=y
>>>>> CONFIG_KALLSYMS_SELFTEST=y
>>>>> CONFIG_KALLSYMS_BASE_RELATIVE=y
>>>>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
>>>>> CONFIG_SYMBOLIC_ERRNAME=y
>>>>> # CONFIG_STRIP_ASM_SYMS is not set
>>>>> CONFIG_KALLSYMS_SELFTEST
>>>>>
>>>>> Do you have a clue?
>>>>
>>>> cat /proc/kallsyms | grep kallsyms_test_func
>>>> Let's see if the compiler-generated symbols have some special suffixes.
>>>
>>> Thanks, looks normal to me:
>>>
>>> atari:~# cat /proc/kallsyms | grep kallsyms_test_func
>>> 00060ab0 t kallsyms_test_func_static
>>> 00060ac0 T kallsyms_test_func
>>> 00060ac2 W kallsyms_test_func_weak
>>> atari:~#
>>
>> It's incredible. I don't have a m68k environment and I'm trying to build a qemu
>> environment. If you're in a hurry and willing, you can apply the debugging patch
>> in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
>> the output information.
>
> Still fails:
>
> tst: found kallsyms_test_func at index=12845
> tst: [12533] = kallsyms_test_func, seq=17370, offset=191223
> tst: [18800] = kallsyms_test_func, seq=23193, offset=259263
> tst: [21934] = kallsyms_test_func, seq=2527, offset=22331
> tst: [23501] = kallsyms_test_func, seq=11792, offset=126366
> tst: [24284] = kallsyms_test_func, seq=8427, offset=87395
> tst: [24676] = kallsyms_test_func, seq=21896, offset=243536
> tst: [24872] = kallsyms_test_func, seq=22571, offset=251856
> tst: [24970] = kallsyms_test_func, seq=23264, offset=260074
> tst: [25019] = kallsyms_test_func, seq=9003, offset=93752
> tst: [25043] = kallsyms_test_func, seq=14324, offset=155117
> tst: [25055] = kallsyms_test_func, seq=5942, offset=62266
> tst: [25061] = kallsyms_test_func, seq=14347, offset=155467
> tst: [25064] = kallsyms_test_func, seq=14350, offset=155512
> tst: [25066] = kallsyms_test_func, seq=14346, offset=155457
> tst: [25067] = kallsyms_test_func, seq=14354, offset=155565

- pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, name, seq, off);
+ pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, namebuf, seq, off);

Sorry, a variable in the debugging code is incorrectly written. 'name' should
be replaced with 'namebuf', then we can see which function the comparison is wrong.

>
> However, the binary search sequence looks very suspicious.
> After investigation, it turns out compare_symbol_name() and strcmp()
> always return positive numbers.
>
> Looks like commit 3bc753c06dd02a35 ("kbuild: treat char as always
> unsigned") is to blame.

Oh, maybe you can "git reset --hard 30f3bb09778de64" and try again.
30f3bb09778de64 kallsyms: Add self-test facility

But the latest kernel is OK on x86. So other patches are unlikely to
affect this function.

Is m68k big-endian?

>
> Changing:
>
> --- a/arch/m68k/include/asm/string.h
> +++ b/arch/m68k/include/asm/string.h
> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
> char *src, size_t n)
> #define __HAVE_ARCH_STRCMP
> static inline int strcmp(const char *cs, const char *ct)
> {
> - char res;
> + signed char res;
>
> asm ("\n"
> "1: move.b (%0)+,%2\n" /* get *cs */
>
> fixes strcmp, but the test still fails:
>
> tst: kallsyms_lookup_names() is OK, name=kallsyms_test_func, i=0

i=0, i is impossible zero. Maybe kallsyms_lookup_names() always return success now.

> kallsyms_selftest: kallsyms_lookup_name() for
> kallsyms_test_func_static failed: addr=8e1c, expect 60cd4
> kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func
> failed: addr=8e1c, expect 60ce4
> kallsyms_selftest: kallsyms_lookup_name() for
> kallsyms_test_func_weak failed: addr=8e1c, expect 60ce6
> kallsyms_selftest: kallsyms_lookup_name() for vmalloc failed:
> addr=8e1c, expect c2946
> kallsyms_selftest: kallsyms_lookup_name() for vfree failed:
> addr=8e1c, expect c235e
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func_static failed: count=25068, addr=1f3d3c, expect
> 60cd4
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func failed: count=25068, addr=1f3d3c, expect 60ce4
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func_weak failed: count=25068, addr=1f3d3c, expect 60ce6
> kallsyms_selftest: kallsyms_on_each_match_symbol() for vmalloc
> failed: count=25068, addr=1f3d3c, expect c2946
> kallsyms_selftest: kallsyms_on_each_match_symbol() for vfree
> failed: count=25068, addr=1f3d3c, expect c235e
> kallsyms_selftest: abort
>
> Dropping -funsigned-char doesn't improve upon that...
>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
> -- Linus Torvalds
>
> .
>

--
Regards,
Zhen Lei

2022-12-15 15:05:08

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/15 21:58, Leizhen (ThunderTown) wrote:
>
>
> On 2022/12/15 21:24, Geert Uytterhoeven wrote:
>> Hi Zhen,
>>
>> CC Jason
>>
>> On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
>> <[email protected]> wrote:
>>> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
>>>> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
>>>> <[email protected]> wrote:
>>>>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
>>>>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
>>>>>>> Added test cases for basic functions and performance of functions
>>>>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
>>>>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
>>>>>>> of the kallsyms compression algorithm for the current symbol set.
>>>>>>>
>>>>>>> The basic functions test begins by testing a set of symbols whose address
>>>>>>> values are known. Then, traverse all symbol addresses and find the
>>>>>>> corresponding symbol name based on the address. It's impossible to
>>>>>>> determine whether these addresses are correct, but we can use the above
>>>>>>> three functions along with the addresses to test each other. Due to the
>>>>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
>>>>>>> symbols can be tested in one second, so let it test on average once
>>>>>>> every 128 symbols. The other two functions validate all symbols.
>>>>>>>
>>>>>>> If the basic functions test is passed, print only performance test
>>>>>>> results. If the test fails, print error information, but do not perform
>>>>>>> subsequent performance tests.
>>>>>>>
>>>>>>> Start self-test automatically after system startup if
>>>>>>> CONFIG_KALLSYMS_SELFTEST=y.
>>>>>>>
>>>>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
>>>>>>> start
>>>>>>> ---------------------------------------------------------
>>>>>>> | nr_symbols | compressed size | original size | ratio(%) |
>>>>>>> |---------------------------------------------------------|
>>>>>>> | 107543 | 1357912 | 2407433 | 56.40 |
>>>>>>> ---------------------------------------------------------
>>>>>>> kallsyms_lookup_name() looked up 107543 symbols
>>>>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
>>>>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
>>>>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
>>>>>>> finish
>>>>>>>
>>>>>>> Signed-off-by: Zhen Lei <[email protected]>
>>>>>>
>>>>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
>>>>>> Add self-test facility") in linus/master.
>>>>>>
>>>>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
>>>>>> but it failed:
>>>>>>
>>>>>> start
>>>>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
>>>>>> addr=0, expect 60ab0
>>>>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
>>>>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
>>>>>> expect 60ac2
>>>>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
>>>>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
>>>>>> failed: count=0, addr=0, expect 60ab0
>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
>>>>>> count=0, addr=0, expect 60ac0
>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
>>>>>> failed: count=0, addr=0, expect 60ac2
>>>>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
>>>>>> addr=0, expect c272a
>>>>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
>>>>>> expect c2142
>>>>>> abort
>>>>>>
>>>>>> Given all addresses are zero, it looks like some required functionality
>>>>>> or config option is missing.
>>>>>>
>>>>>> $ grep SYM .config
>>>>>> CONFIG_KALLSYMS=y
>>>>>> CONFIG_KALLSYMS_SELFTEST=y
>>>>>> CONFIG_KALLSYMS_BASE_RELATIVE=y
>>>>>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
>>>>>> CONFIG_SYMBOLIC_ERRNAME=y
>>>>>> # CONFIG_STRIP_ASM_SYMS is not set
>>>>>> CONFIG_KALLSYMS_SELFTEST
>>>>>>
>>>>>> Do you have a clue?
>>>>>
>>>>> cat /proc/kallsyms | grep kallsyms_test_func
>>>>> Let's see if the compiler-generated symbols have some special suffixes.
>>>>
>>>> Thanks, looks normal to me:
>>>>
>>>> atari:~# cat /proc/kallsyms | grep kallsyms_test_func
>>>> 00060ab0 t kallsyms_test_func_static
>>>> 00060ac0 T kallsyms_test_func
>>>> 00060ac2 W kallsyms_test_func_weak
>>>> atari:~#
>>>
>>> It's incredible. I don't have a m68k environment and I'm trying to build a qemu
>>> environment. If you're in a hurry and willing, you can apply the debugging patch
>>> in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
>>> the output information.
>>
>> Still fails:
>>
>> tst: found kallsyms_test_func at index=12845
>> tst: [12533] = kallsyms_test_func, seq=17370, offset=191223
>> tst: [18800] = kallsyms_test_func, seq=23193, offset=259263
>> tst: [21934] = kallsyms_test_func, seq=2527, offset=22331
>> tst: [23501] = kallsyms_test_func, seq=11792, offset=126366
>> tst: [24284] = kallsyms_test_func, seq=8427, offset=87395
>> tst: [24676] = kallsyms_test_func, seq=21896, offset=243536
>> tst: [24872] = kallsyms_test_func, seq=22571, offset=251856
>> tst: [24970] = kallsyms_test_func, seq=23264, offset=260074
>> tst: [25019] = kallsyms_test_func, seq=9003, offset=93752
>> tst: [25043] = kallsyms_test_func, seq=14324, offset=155117
>> tst: [25055] = kallsyms_test_func, seq=5942, offset=62266
>> tst: [25061] = kallsyms_test_func, seq=14347, offset=155467
>> tst: [25064] = kallsyms_test_func, seq=14350, offset=155512
>> tst: [25066] = kallsyms_test_func, seq=14346, offset=155457
>> tst: [25067] = kallsyms_test_func, seq=14354, offset=155565
>
> - pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, name, seq, off);
> + pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, namebuf, seq, off);
>
> Sorry, a variable in the debugging code is incorrectly written. 'name' should
> be replaced with 'namebuf', then we can see which function the comparison is wrong.

I attached debug patch v2.

>
>>
>> However, the binary search sequence looks very suspicious.
>> After investigation, it turns out compare_symbol_name() and strcmp()
>> always return positive numbers.
>>
>> Looks like commit 3bc753c06dd02a35 ("kbuild: treat char as always
>> unsigned") is to blame.
>
> Oh, maybe you can "git reset --hard 30f3bb09778de64" and try again.
> 30f3bb09778de64 kallsyms: Add self-test facility
>
> But the latest kernel is OK on x86. So other patches are unlikely to
> affect this function.
>
> Is m68k big-endian?
>
>>
>> Changing:
>>
>> --- a/arch/m68k/include/asm/string.h
>> +++ b/arch/m68k/include/asm/string.h
>> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
>> char *src, size_t n)
>> #define __HAVE_ARCH_STRCMP
>> static inline int strcmp(const char *cs, const char *ct)
>> {
>> - char res;
>> + signed char res;
>>
>> asm ("\n"
>> "1: move.b (%0)+,%2\n" /* get *cs */
>>
>> fixes strcmp, but the test still fails:
>>
>> tst: kallsyms_lookup_names() is OK, name=kallsyms_test_func, i=0
>
> i=0, i is impossible zero. Maybe kallsyms_lookup_names() always return success now.
>
>> kallsyms_selftest: kallsyms_lookup_name() for
>> kallsyms_test_func_static failed: addr=8e1c, expect 60cd4
>> kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func
>> failed: addr=8e1c, expect 60ce4
>> kallsyms_selftest: kallsyms_lookup_name() for
>> kallsyms_test_func_weak failed: addr=8e1c, expect 60ce6
>> kallsyms_selftest: kallsyms_lookup_name() for vmalloc failed:
>> addr=8e1c, expect c2946
>> kallsyms_selftest: kallsyms_lookup_name() for vfree failed:
>> addr=8e1c, expect c235e
>> kallsyms_selftest: kallsyms_on_each_match_symbol() for
>> kallsyms_test_func_static failed: count=25068, addr=1f3d3c, expect
>> 60cd4
>> kallsyms_selftest: kallsyms_on_each_match_symbol() for
>> kallsyms_test_func failed: count=25068, addr=1f3d3c, expect 60ce4
>> kallsyms_selftest: kallsyms_on_each_match_symbol() for
>> kallsyms_test_func_weak failed: count=25068, addr=1f3d3c, expect 60ce6
>> kallsyms_selftest: kallsyms_on_each_match_symbol() for vmalloc
>> failed: count=25068, addr=1f3d3c, expect c2946
>> kallsyms_selftest: kallsyms_on_each_match_symbol() for vfree
>> failed: count=25068, addr=1f3d3c, expect c235e
>> kallsyms_selftest: abort
>>
>> Dropping -funsigned-char doesn't improve upon that...
>>
>> Gr{oetje,eeting}s,
>>
>> Geert
>>
>> --
>> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>>
>> In personal conversations with technical people, I call myself a hacker. But
>> when I'm talking to journalists I just say "programmer" or something like that.
>> -- Linus Torvalds
>>
>> .
>>
>

--
Regards,
Zhen Lei


Attachments:
0001-kallsyms-debug-m68k.patch (2.70 kB)

2022-12-15 15:06:46

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Thu, Dec 15, 2022 at 3:40 PM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/15 21:58, Leizhen (ThunderTown) wrote:
> > On 2022/12/15 21:24, Geert Uytterhoeven wrote:
> >> On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
> >> <[email protected]> wrote:
> >>> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
> >>>> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
> >>>> <[email protected]> wrote:
> >>>>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
> >>>>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
> >>>>>>> Added test cases for basic functions and performance of functions
> >>>>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> >>>>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> >>>>>>> of the kallsyms compression algorithm for the current symbol set.
> >>>>>>>
> >>>>>>> The basic functions test begins by testing a set of symbols whose address
> >>>>>>> values are known. Then, traverse all symbol addresses and find the
> >>>>>>> corresponding symbol name based on the address. It's impossible to
> >>>>>>> determine whether these addresses are correct, but we can use the above
> >>>>>>> three functions along with the addresses to test each other. Due to the
> >>>>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> >>>>>>> symbols can be tested in one second, so let it test on average once
> >>>>>>> every 128 symbols. The other two functions validate all symbols.
> >>>>>>>
> >>>>>>> If the basic functions test is passed, print only performance test
> >>>>>>> results. If the test fails, print error information, but do not perform
> >>>>>>> subsequent performance tests.
> >>>>>>>
> >>>>>>> Start self-test automatically after system startup if
> >>>>>>> CONFIG_KALLSYMS_SELFTEST=y.
> >>>>>>>
> >>>>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> >>>>>>> start
> >>>>>>> ---------------------------------------------------------
> >>>>>>> | nr_symbols | compressed size | original size | ratio(%) |
> >>>>>>> |---------------------------------------------------------|
> >>>>>>> | 107543 | 1357912 | 2407433 | 56.40 |
> >>>>>>> ---------------------------------------------------------
> >>>>>>> kallsyms_lookup_name() looked up 107543 symbols
> >>>>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> >>>>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
> >>>>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> >>>>>>> finish
> >>>>>>>
> >>>>>>> Signed-off-by: Zhen Lei <[email protected]>
> >>>>>>
> >>>>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
> >>>>>> Add self-test facility") in linus/master.
> >>>>>>
> >>>>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
> >>>>>> but it failed:
> >>>>>>
> >>>>>> start
> >>>>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
> >>>>>> addr=0, expect 60ab0
> >>>>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
> >>>>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
> >>>>>> expect 60ac2
> >>>>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
> >>>>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
> >>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> >>>>>> failed: count=0, addr=0, expect 60ab0
> >>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> >>>>>> count=0, addr=0, expect 60ac0
> >>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> >>>>>> failed: count=0, addr=0, expect 60ac2
> >>>>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
> >>>>>> addr=0, expect c272a
> >>>>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
> >>>>>> expect c2142
> >>>>>> abort
> >>>>>>
> >>>>>> Given all addresses are zero, it looks like some required functionality
> >>>>>> or config option is missing.
> >>>>>>
> >>>>>> $ grep SYM .config
> >>>>>> CONFIG_KALLSYMS=y
> >>>>>> CONFIG_KALLSYMS_SELFTEST=y
> >>>>>> CONFIG_KALLSYMS_BASE_RELATIVE=y
> >>>>>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
> >>>>>> CONFIG_SYMBOLIC_ERRNAME=y
> >>>>>> # CONFIG_STRIP_ASM_SYMS is not set
> >>>>>> CONFIG_KALLSYMS_SELFTEST
> >>>>>>
> >>>>>> Do you have a clue?
> >>>>>
> >>>>> cat /proc/kallsyms | grep kallsyms_test_func
> >>>>> Let's see if the compiler-generated symbols have some special suffixes.
> >>>>
> >>>> Thanks, looks normal to me:
> >>>>
> >>>> atari:~# cat /proc/kallsyms | grep kallsyms_test_func
> >>>> 00060ab0 t kallsyms_test_func_static
> >>>> 00060ac0 T kallsyms_test_func
> >>>> 00060ac2 W kallsyms_test_func_weak
> >>>> atari:~#
> >>>
> >>> It's incredible. I don't have a m68k environment and I'm trying to build a qemu
> >>> environment. If you're in a hurry and willing, you can apply the debugging patch
> >>> in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
> >>> the output information.
> >>
> >> Still fails:
> >>
> >> tst: found kallsyms_test_func at index=12845
> >> tst: [12533] = kallsyms_test_func, seq=17370, offset=191223
> >> tst: [18800] = kallsyms_test_func, seq=23193, offset=259263
> >> tst: [21934] = kallsyms_test_func, seq=2527, offset=22331
> >> tst: [23501] = kallsyms_test_func, seq=11792, offset=126366
> >> tst: [24284] = kallsyms_test_func, seq=8427, offset=87395
> >> tst: [24676] = kallsyms_test_func, seq=21896, offset=243536
> >> tst: [24872] = kallsyms_test_func, seq=22571, offset=251856
> >> tst: [24970] = kallsyms_test_func, seq=23264, offset=260074
> >> tst: [25019] = kallsyms_test_func, seq=9003, offset=93752
> >> tst: [25043] = kallsyms_test_func, seq=14324, offset=155117
> >> tst: [25055] = kallsyms_test_func, seq=5942, offset=62266
> >> tst: [25061] = kallsyms_test_func, seq=14347, offset=155467
> >> tst: [25064] = kallsyms_test_func, seq=14350, offset=155512
> >> tst: [25066] = kallsyms_test_func, seq=14346, offset=155457
> >> tst: [25067] = kallsyms_test_func, seq=14354, offset=155565
> >
> > - pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, name, seq, off);
> > + pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, namebuf, seq, off);
> >
> > Sorry, a variable in the debugging code is incorrectly written. 'name' should
> > be replaced with 'namebuf', then we can see which function the comparison is wrong.
>
> I attached debug patch v2.

On 30f3bb09778de64 with your debug patch v2:

kallsyms_selftest: start
tst: kallsyms_lookup_names() is OK, name=kallsyms_test_func, i=0
kallsyms_selftest: kallsyms_lookup_name() for
kallsyms_test_func_static failed: addr=8dbc, expect 60498
kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func
failed: addr=8dbc, expect 604a8
kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func_weak
failed: addr=8dbc, expect 604aa
kallsyms_selftest: kallsyms_lookup_name() for vmalloc failed:
addr=8dbc, expect bde18
kallsyms_selftest: kallsyms_lookup_name() for vfree failed: addr=8dbc,
expect bd86e
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func_static failed: count=24891, addr=1eea00, expect
60498
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func failed: count=24891, addr=1eea00, expect 604a8
kallsyms_selftest: kallsyms_on_each_match_symbol() for
kallsyms_test_func_weak failed: count=24891, addr=1eea00, expect 604aa
kallsyms_selftest: kallsyms_on_each_match_symbol() for vmalloc failed:
count=24891, addr=1eea00, expect bde18
kallsyms_selftest: kallsyms_on_each_match_symbol() for vfree failed:
count=24891, addr=1eea00, expect bd86e
kallsyms_selftest: abort

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-15 15:14:28

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 15 2022, Geert Uytterhoeven wrote:

> start
> kallsyms_lookup_name() for kallsyms_test_func_static failed:
> addr=8dbc, expect 60308
> kallsyms_lookup_name() for kallsyms_test_func failed: addr=8dbc,
> expect 60318
> kallsyms_lookup_name() for kallsyms_test_func_weak failed:
> addr=8dbc, expect 6031a
> kallsyms_lookup_name() for vmalloc failed: addr=8dbc, expect bdc88
> kallsyms_lookup_name() for vfree failed: addr=8dbc, expect bd6de

Curiously addr always comes out the same. What symbol does it resolve
to?

> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> failed: count=24890, addr=1ee870, expect 60308
> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> count=24890, addr=1ee870, expect 60318
> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> failed: count=24890, addr=1ee870, expect 6031a
> kallsyms_on_each_match_symbol() for vmalloc failed: count=24890,
> addr=1ee870, expect bdc88
> kallsyms_on_each_match_symbol() for vfree failed: count=24890,
> addr=1ee870, expect bd6de

Here too.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-15 15:43:58

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Thu, Dec 15, 2022 at 2:58 PM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/15 21:24, Geert Uytterhoeven wrote:
> > On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
> > <[email protected]> wrote:
> >> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
> >>> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
> >>> <[email protected]> wrote:
> >>>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
> >>>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
> >>>>>> Added test cases for basic functions and performance of functions
> >>>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
> >>>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
> >>>>>> of the kallsyms compression algorithm for the current symbol set.
> >>>>>>
> >>>>>> The basic functions test begins by testing a set of symbols whose address
> >>>>>> values are known. Then, traverse all symbol addresses and find the
> >>>>>> corresponding symbol name based on the address. It's impossible to
> >>>>>> determine whether these addresses are correct, but we can use the above
> >>>>>> three functions along with the addresses to test each other. Due to the
> >>>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
> >>>>>> symbols can be tested in one second, so let it test on average once
> >>>>>> every 128 symbols. The other two functions validate all symbols.
> >>>>>>
> >>>>>> If the basic functions test is passed, print only performance test
> >>>>>> results. If the test fails, print error information, but do not perform
> >>>>>> subsequent performance tests.
> >>>>>>
> >>>>>> Start self-test automatically after system startup if
> >>>>>> CONFIG_KALLSYMS_SELFTEST=y.
> >>>>>>
> >>>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
> >>>>>> start
> >>>>>> ---------------------------------------------------------
> >>>>>> | nr_symbols | compressed size | original size | ratio(%) |
> >>>>>> |---------------------------------------------------------|
> >>>>>> | 107543 | 1357912 | 2407433 | 56.40 |
> >>>>>> ---------------------------------------------------------
> >>>>>> kallsyms_lookup_name() looked up 107543 symbols
> >>>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
> >>>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
> >>>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
> >>>>>> finish
> >>>>>>
> >>>>>> Signed-off-by: Zhen Lei <[email protected]>
> >>>>>
> >>>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
> >>>>> Add self-test facility") in linus/master.
> >>>>>
> >>>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
> >>>>> but it failed:
> >>>>>
> >>>>> start
> >>>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
> >>>>> addr=0, expect 60ab0
> >>>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
> >>>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
> >>>>> expect 60ac2
> >>>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
> >>>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
> >>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
> >>>>> failed: count=0, addr=0, expect 60ab0
> >>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
> >>>>> count=0, addr=0, expect 60ac0
> >>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
> >>>>> failed: count=0, addr=0, expect 60ac2
> >>>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
> >>>>> addr=0, expect c272a
> >>>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
> >>>>> expect c2142
> >>>>> abort

> Oh, maybe you can "git reset --hard 30f3bb09778de64" and try again.
> 30f3bb09778de64 kallsyms: Add self-test facility
>
> But the latest kernel is OK on x86. So other patches are unlikely to
> affect this function.

On 30f3bb09778de64 it fails the same way:

start
kallsyms_lookup_name() for kallsyms_test_func_static failed:
addr=8dbc, expect 60308
kallsyms_lookup_name() for kallsyms_test_func failed: addr=8dbc,
expect 60318
kallsyms_lookup_name() for kallsyms_test_func_weak failed:
addr=8dbc, expect 6031a
kallsyms_lookup_name() for vmalloc failed: addr=8dbc, expect bdc88
kallsyms_lookup_name() for vfree failed: addr=8dbc, expect bd6de
kallsyms_on_each_match_symbol() for kallsyms_test_func_static
failed: count=24890, addr=1ee870, expect 60308
kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
count=24890, addr=1ee870, expect 60318
kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
failed: count=24890, addr=1ee870, expect 6031a
kallsyms_on_each_match_symbol() for vmalloc failed: count=24890,
addr=1ee870, expect bdc88
kallsyms_on_each_match_symbol() for vfree failed: count=24890,
addr=1ee870, expect bd6de
abort

> Is m68k big-endian?

Yes it is. And 32-bit values are aligned to only 2 bytes.

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-16 08:16:37

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/15 22:51, Geert Uytterhoeven wrote:
> Hi Zhen,
>
> On Thu, Dec 15, 2022 at 3:40 PM Leizhen (ThunderTown)
> <[email protected]> wrote:
>> On 2022/12/15 21:58, Leizhen (ThunderTown) wrote:
>>> On 2022/12/15 21:24, Geert Uytterhoeven wrote:
>>>> On Thu, Dec 15, 2022 at 1:34 PM Leizhen (ThunderTown)
>>>> <[email protected]> wrote:
>>>>> On 2022/12/15 17:39, Geert Uytterhoeven wrote:
>>>>>> On Thu, Dec 15, 2022 at 10:16 AM Leizhen (ThunderTown)
>>>>>> <[email protected]> wrote:
>>>>>>> On 2022/12/15 16:50, Geert Uytterhoeven wrote:
>>>>>>>> On Tue, Nov 15, 2022 at 9:41 AM Zhen Lei <[email protected]> wrote:
>>>>>>>>> Added test cases for basic functions and performance of functions
>>>>>>>>> kallsyms_lookup_name(), kallsyms_on_each_symbol() and
>>>>>>>>> kallsyms_on_each_match_symbol(). It also calculates the compression rate
>>>>>>>>> of the kallsyms compression algorithm for the current symbol set.
>>>>>>>>>
>>>>>>>>> The basic functions test begins by testing a set of symbols whose address
>>>>>>>>> values are known. Then, traverse all symbol addresses and find the
>>>>>>>>> corresponding symbol name based on the address. It's impossible to
>>>>>>>>> determine whether these addresses are correct, but we can use the above
>>>>>>>>> three functions along with the addresses to test each other. Due to the
>>>>>>>>> traversal operation of kallsyms_on_each_symbol() is too slow, only 60
>>>>>>>>> symbols can be tested in one second, so let it test on average once
>>>>>>>>> every 128 symbols. The other two functions validate all symbols.
>>>>>>>>>
>>>>>>>>> If the basic functions test is passed, print only performance test
>>>>>>>>> results. If the test fails, print error information, but do not perform
>>>>>>>>> subsequent performance tests.
>>>>>>>>>
>>>>>>>>> Start self-test automatically after system startup if
>>>>>>>>> CONFIG_KALLSYMS_SELFTEST=y.
>>>>>>>>>
>>>>>>>>> Example of output content: (prefix 'kallsyms_selftest:' is omitted
>>>>>>>>> start
>>>>>>>>> ---------------------------------------------------------
>>>>>>>>> | nr_symbols | compressed size | original size | ratio(%) |
>>>>>>>>> |---------------------------------------------------------|
>>>>>>>>> | 107543 | 1357912 | 2407433 | 56.40 |
>>>>>>>>> ---------------------------------------------------------
>>>>>>>>> kallsyms_lookup_name() looked up 107543 symbols
>>>>>>>>> The time spent on each symbol is (ns): min=630, max=35295, avg=7353
>>>>>>>>> kallsyms_on_each_symbol() traverse all: 11782628 ns
>>>>>>>>> kallsyms_on_each_match_symbol() traverse all: 9261 ns
>>>>>>>>> finish
>>>>>>>>>
>>>>>>>>> Signed-off-by: Zhen Lei <[email protected]>
>>>>>>>>
>>>>>>>> Thanks for your patch, which is now commit 30f3bb09778de64e ("kallsyms:
>>>>>>>> Add self-test facility") in linus/master.
>>>>>>>>
>>>>>>>> I gave this a try on m68k (atari_defconfig + CONFIG_KALLSYMS_SELFTEST=y),
>>>>>>>> but it failed:
>>>>>>>>
>>>>>>>> start
>>>>>>>> kallsyms_lookup_name() for kallsyms_test_func_static failed:
>>>>>>>> addr=0, expect 60ab0
>>>>>>>> kallsyms_lookup_name() for kallsyms_test_func failed: addr=0, expect 60ac0
>>>>>>>> kallsyms_lookup_name() for kallsyms_test_func_weak failed: addr=0,
>>>>>>>> expect 60ac2
>>>>>>>> kallsyms_lookup_name() for vmalloc failed: addr=0, expect c272a
>>>>>>>> kallsyms_lookup_name() for vfree failed: addr=0, expect c2142
>>>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_static
>>>>>>>> failed: count=0, addr=0, expect 60ab0
>>>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func failed:
>>>>>>>> count=0, addr=0, expect 60ac0
>>>>>>>> kallsyms_on_each_match_symbol() for kallsyms_test_func_weak
>>>>>>>> failed: count=0, addr=0, expect 60ac2
>>>>>>>> kallsyms_on_each_match_symbol() for vmalloc failed: count=0,
>>>>>>>> addr=0, expect c272a
>>>>>>>> kallsyms_on_each_match_symbol() for vfree failed: count=0, addr=0,
>>>>>>>> expect c2142
>>>>>>>> abort
>>>>>>>>
>>>>>>>> Given all addresses are zero, it looks like some required functionality
>>>>>>>> or config option is missing.
>>>>>>>>
>>>>>>>> $ grep SYM .config
>>>>>>>> CONFIG_KALLSYMS=y
>>>>>>>> CONFIG_KALLSYMS_SELFTEST=y
>>>>>>>> CONFIG_KALLSYMS_BASE_RELATIVE=y
>>>>>>>> # CONFIG_ASYMMETRIC_KEY_TYPE is not set
>>>>>>>> CONFIG_SYMBOLIC_ERRNAME=y
>>>>>>>> # CONFIG_STRIP_ASM_SYMS is not set
>>>>>>>> CONFIG_KALLSYMS_SELFTEST
>>>>>>>>
>>>>>>>> Do you have a clue?
>>>>>>>
>>>>>>> cat /proc/kallsyms | grep kallsyms_test_func
>>>>>>> Let's see if the compiler-generated symbols have some special suffixes.
>>>>>>
>>>>>> Thanks, looks normal to me:
>>>>>>
>>>>>> atari:~# cat /proc/kallsyms | grep kallsyms_test_func
>>>>>> 00060ab0 t kallsyms_test_func_static
>>>>>> 00060ac0 T kallsyms_test_func
>>>>>> 00060ac2 W kallsyms_test_func_weak
>>>>>> atari:~#
>>>>>
>>>>> It's incredible. I don't have a m68k environment and I'm trying to build a qemu
>>>>> environment. If you're in a hurry and willing, you can apply the debugging patch
>>>>> in the attachment. I'd like to see what's wrong. Use "dmesg | grep tst" to collect
>>>>> the output information.
>>>>
>>>> Still fails:
>>>>
>>>> tst: found kallsyms_test_func at index=12845
>>>> tst: [12533] = kallsyms_test_func, seq=17370, offset=191223
>>>> tst: [18800] = kallsyms_test_func, seq=23193, offset=259263
>>>> tst: [21934] = kallsyms_test_func, seq=2527, offset=22331
>>>> tst: [23501] = kallsyms_test_func, seq=11792, offset=126366
>>>> tst: [24284] = kallsyms_test_func, seq=8427, offset=87395
>>>> tst: [24676] = kallsyms_test_func, seq=21896, offset=243536
>>>> tst: [24872] = kallsyms_test_func, seq=22571, offset=251856
>>>> tst: [24970] = kallsyms_test_func, seq=23264, offset=260074
>>>> tst: [25019] = kallsyms_test_func, seq=9003, offset=93752
>>>> tst: [25043] = kallsyms_test_func, seq=14324, offset=155117
>>>> tst: [25055] = kallsyms_test_func, seq=5942, offset=62266
>>>> tst: [25061] = kallsyms_test_func, seq=14347, offset=155467
>>>> tst: [25064] = kallsyms_test_func, seq=14350, offset=155512
>>>> tst: [25066] = kallsyms_test_func, seq=14346, offset=155457
>>>> tst: [25067] = kallsyms_test_func, seq=14354, offset=155565
>>>
>>> - pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, name, seq, off);
>>> + pr_warn("tst: [%d] = %s, seq=%d, offset=%d\n", mid, namebuf, seq, off);
>>>
>>> Sorry, a variable in the debugging code is incorrectly written. 'name' should
>>> be replaced with 'namebuf', then we can see which function the comparison is wrong.
>>
>> I attached debug patch v2.
>
> On 30f3bb09778de64 with your debug patch v2:

I've set up the qemu environment, and I'll try to solve it by tomorrow at the latest.

>
> kallsyms_selftest: start
> tst: kallsyms_lookup_names() is OK, name=kallsyms_test_func, i=0
> kallsyms_selftest: kallsyms_lookup_name() for
> kallsyms_test_func_static failed: addr=8dbc, expect 60498
> kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func
> failed: addr=8dbc, expect 604a8
> kallsyms_selftest: kallsyms_lookup_name() for kallsyms_test_func_weak
> failed: addr=8dbc, expect 604aa
> kallsyms_selftest: kallsyms_lookup_name() for vmalloc failed:
> addr=8dbc, expect bde18
> kallsyms_selftest: kallsyms_lookup_name() for vfree failed: addr=8dbc,
> expect bd86e
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func_static failed: count=24891, addr=1eea00, expect
> 60498
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func failed: count=24891, addr=1eea00, expect 604a8
> kallsyms_selftest: kallsyms_on_each_match_symbol() for
> kallsyms_test_func_weak failed: count=24891, addr=1eea00, expect 604aa
> kallsyms_selftest: kallsyms_on_each_match_symbol() for vmalloc failed:
> count=24891, addr=1eea00, expect bde18
> kallsyms_selftest: kallsyms_on_each_match_symbol() for vfree failed:
> count=24891, addr=1eea00, expect bd86e
> kallsyms_selftest: abort
>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
> -- Linus Torvalds
>
> .
>

--
Regards,
Zhen Lei

2022-12-16 10:28:19

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 15:42, Leizhen (ThunderTown) wrote:
>
>
> On 2022/12/15 22:51, Geert Uytterhoeven wrote:
>> Hi Zhen,
>>
>>
>> On 30f3bb09778de64 with your debug patch v2:
>
> I've set up the qemu environment, and I'll try to solve it by tomorrow at the latest.

It seems that the problem is still strcmp(). After I commented strcmp() in
arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
it works well.

The output i=0, because compare_symbol_name() always return zero in below loop.
'low' decreases to 0, then the loop ends.
The reason is not clear. I'm still analyzing it.

low = mid;
while (low) {
seq = get_symbol_seq(low - 1);
off = get_symbol_offset(seq);
kallsyms_expand_symbol(off, namebuf, ARRAY_SIZE(namebuf));
if (compare_symbol_name(name, namebuf))
break;
low--;
}
*start = low;


>
>>
>>
>> Gr{oetje,eeting}s,
>>
>> Geert
>>
>> --
>> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>>
>> In personal conversations with technical people, I call myself a hacker. But
>> when I'm talking to journalists I just say "programmer" or something like that.
>> -- Linus Torvalds
>>
>> .
>>
>

--
Regards,
Zhen Lei

2022-12-16 11:30:10

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Geert Uytterhoeven
> Sent: 15 December 2022 13:25
...
> Looks like commit 3bc753c06dd02a35 ("kbuild: treat char as always
> unsigned") is to blame.
>
> Changing:
>
> --- a/arch/m68k/include/asm/string.h
> +++ b/arch/m68k/include/asm/string.h
> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
> char *src, size_t n)
> #define __HAVE_ARCH_STRCMP
> static inline int strcmp(const char *cs, const char *ct)
> {
> - char res;
> + signed char res;
>
> asm ("\n"
> "1: move.b (%0)+,%2\n" /* get *cs */
>
> fixes strcmp, but the test still fails:

Try 'int res;' and an explicit sign extend (I think):
"3: extb %2\n"

The strcmp() is still wrong if either input string
has characters with the top bit set.
The result needs to be based of the carry flag not
the sign of the byte subtract.

It is too long since I've written m68k asm.
I've checked, all byte operations leave the high 24bits
unchanged.
So it is possible that gcc is making assumptions and
skipping the sign extend under some circumstances.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 11:44:14

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 18:40, David Laight wrote:
> From: Geert Uytterhoeven
>> Sent: 15 December 2022 13:25
> ...
>> Looks like commit 3bc753c06dd02a35 ("kbuild: treat char as always
>> unsigned") is to blame.
>>
>> Changing:
>>
>> --- a/arch/m68k/include/asm/string.h
>> +++ b/arch/m68k/include/asm/string.h
>> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
>> char *src, size_t n)
>> #define __HAVE_ARCH_STRCMP
>> static inline int strcmp(const char *cs, const char *ct)
>> {
>> - char res;
>> + signed char res;
>>
>> asm ("\n"
>> "1: move.b (%0)+,%2\n" /* get *cs */
>>
>> fixes strcmp, but the test still fails:
>
> Try 'int res;' and an explicit sign extend (I think):
> "3: extb %2\n"

Compilation failed. I tried "return (int)(signed char)res;", it's still failed.

>
> The strcmp() is still wrong if either input string
> has characters with the top bit set.
> The result needs to be based of the carry flag not
> the sign of the byte subtract.
>
> It is too long since I've written m68k asm.
> I've checked, all byte operations leave the high 24bits
> unchanged.

Currently, only ASCCIs. So it won't be the reason.

> So it is possible that gcc is making assumptions and
> skipping the sign extend under some circumstances.

Wow, because compare_symbol_name() works properly during the previous binary
search, the compiler must have done something bad. So I add 'volatile' to prevent
compiler optimizations, and it's OK now.

diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
index f759d944c449940..3db81e5a783c72a 100644
--- a/arch/m68k/include/asm/string.h
+++ b/arch/m68k/include/asm/string.h
@@ -42,9 +42,9 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
#define __HAVE_ARCH_STRCMP
static inline int strcmp(const char *cs, const char *ct)
{
- char res;
+ signed char res;

- asm ("\n"
+ asm volatile ("\n"
"1: move.b (%0)+,%2\n" /* get *cs */
" cmp.b (%1)+,%2\n" /* compare a byte */
" jne 2f\n" /* not equal, break out */

>
> David
>
> -
> Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
> Registration No: 1397386 (Wales)
>

--
Regards,
Zhen Lei

2022-12-16 11:54:29

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Fri, Dec 16, 2022 at 10:43 AM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/16 15:42, Leizhen (ThunderTown) wrote:
> > On 2022/12/15 22:51, Geert Uytterhoeven wrote:
> >> On 30f3bb09778de64 with your debug patch v2:
> > I've set up the qemu environment, and I'll try to solve it by tomorrow at the latest.
>
> It seems that the problem is still strcmp(). After I commented strcmp() in
> arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
> it works well.

I can confirm that.

One difference is that the one in lib/string.c always return -1/0/1,
while the m68k version can return other negative or positive numbers.

However, adding:

if (res < 0) return -1;
if (res > 0) return 1;

to the m68k version doesn't make a difference.

Renaming the m68k version (changed to -1/0/1) to m68k_strcmp(), and
the generic version to lib_strcmp(), and adding a wrapper that calls
and compares both, shows that both functions do return the same value,
and the test succeeds.

Moving the m68k version inside lib/string.c makes the test pass, too.
So it must be related to the function being inline, and gcc making
(incorrect) assumptions...

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-16 12:23:23

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 19:44, Andreas Schwab wrote:
> On Dez 15 2022, Geert Uytterhoeven wrote:
>
>> Changing:
>>
>> --- a/arch/m68k/include/asm/string.h
>> +++ b/arch/m68k/include/asm/string.h
>> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
>> char *src, size_t n)
>> #define __HAVE_ARCH_STRCMP
>> static inline int strcmp(const char *cs, const char *ct)
>> {
>> - char res;
>> + signed char res;
>>
>> asm ("\n"
>> "1: move.b (%0)+,%2\n" /* get *cs */
>
> Note that strcmp needs to compute the return value from the difference
> of the _unsigned_ characters. That does not explain the error, though,
> since symbol names don't have characters with the high bit set.

Why consider the high bit? It is not memcmp(). If the high bit is set,
it is the user's fault.


>

--
Regards,
Zhen Lei

2022-12-16 12:23:24

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 15 2022, Geert Uytterhoeven wrote:

> Changing:
>
> --- a/arch/m68k/include/asm/string.h
> +++ b/arch/m68k/include/asm/string.h
> @@ -42,7 +42,7 @@ static inline char *strncpy(char *dest, const
> char *src, size_t n)
> #define __HAVE_ARCH_STRCMP
> static inline int strcmp(const char *cs, const char *ct)
> {
> - char res;
> + signed char res;
>
> asm ("\n"
> "1: move.b (%0)+,%2\n" /* get *cs */

Note that strcmp needs to compute the return value from the difference
of the _unsigned_ characters. That does not explain the error, though,
since symbol names don't have characters with the high bit set.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 12:24:25

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, Leizhen (ThunderTown) wrote:

> It seems that the problem is still strcmp(). After I commented strcmp() in
> arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
> it works well.

Does that help?

diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
index f759d944c449..cdafd67774e0 100644
--- a/arch/m68k/include/asm/string.h
+++ b/arch/m68k/include/asm/string.h
@@ -42,18 +42,19 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
#define __HAVE_ARCH_STRCMP
static inline int strcmp(const char *cs, const char *ct)
{
- char res;
+ int res = 0, tmp = 0;

asm ("\n"
"1: move.b (%0)+,%2\n" /* get *cs */
- " cmp.b (%1)+,%2\n" /* compare a byte */
+ " move.b (%1)+,%3\n" /* get *ct */
+ " cmp.b %3,%2\n" /* compare a byte */
" jne 2f\n" /* not equal, break out */
" tst.b %2\n" /* at end of cs? */
" jne 1b\n" /* no, keep going */
" jra 3f\n" /* strings are equal */
- "2: sub.b -(%1),%2\n" /* *cs - *ct */
+ "2: sub.l %3,%2\n" /* *cs - *ct */
"3:"
- : "+a" (cs), "+a" (ct), "=d" (res));
+ : "+a" (cs), "+a" (ct), "+d" (res), "+d" (tmp));
return res;
}
#endif /* CONFIG_COLDFIRE */

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 12:40:12

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 19:28, Geert Uytterhoeven wrote:
> Hi Zhen,
>
> On Fri, Dec 16, 2022 at 10:43 AM Leizhen (ThunderTown)
> <[email protected]> wrote:
>> On 2022/12/16 15:42, Leizhen (ThunderTown) wrote:
>>> On 2022/12/15 22:51, Geert Uytterhoeven wrote:
>>>> On 30f3bb09778de64 with your debug patch v2:
>>> I've set up the qemu environment, and I'll try to solve it by tomorrow at the latest.
>>
>> It seems that the problem is still strcmp(). After I commented strcmp() in
>> arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
>> it works well.
>
> I can confirm that.
>
> One difference is that the one in lib/string.c always return -1/0/1,
> while the m68k version can return other negative or positive numbers.
>
> However, adding:
>
> if (res < 0) return -1;
> if (res > 0) return 1;
>
> to the m68k version doesn't make a difference.
>
> Renaming the m68k version (changed to -1/0/1) to m68k_strcmp(), and
> the generic version to lib_strcmp(), and adding a wrapper that calls
> and compares both, shows that both functions do return the same value,
> and the test succeeds.
>
> Moving the m68k version inside lib/string.c makes the test pass, too.
> So it must be related to the function being inline, and gcc making
> (incorrect) assumptions...

Yes, it's the compiler's fault. I just replied David Laight:

I added 'volatile' to prevent compiler optimizations, and it's OK now.

diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
index f759d944c449940..3db81e5a783c72a 100644
--- a/arch/m68k/include/asm/string.h
+++ b/arch/m68k/include/asm/string.h
@@ -42,9 +42,9 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
#define __HAVE_ARCH_STRCMP
static inline int strcmp(const char *cs, const char *ct)
{
- char res;
+ signed char res;

- asm ("\n"
+ asm volatile ("\n"
"1: move.b (%0)+,%2\n" /* get *cs */
" cmp.b (%1)+,%2\n" /* compare a byte */
" jne 2f\n" /* not equal, break out */

>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like that.
> -- Linus Torvalds
>
> .
>

--
Regards,
Zhen Lei

2022-12-16 12:54:20

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, Leizhen (ThunderTown) wrote:

> Why consider the high bit? It is not memcmp(). If the high bit is set,
> it is the user's fault.

Nope, the semantics of strcmp are defined on the full CHAR_MIN to
CHAR_MAX range.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 14:01:56

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 20:39, Andreas Schwab wrote:
> On Dez 16 2022, Leizhen (ThunderTown) wrote:
>
>> Why consider the high bit? It is not memcmp(). If the high bit is set,
>> it is the user's fault.
>
> Nope, the semantics of strcmp are defined on the full CHAR_MIN to
> CHAR_MAX range.

OK, I got it.

>

--
Regards,
Zhen Lei

2022-12-16 14:06:45

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/16 19:57, Andreas Schwab wrote:
> On Dez 16 2022, Leizhen (ThunderTown) wrote:
>
>> It seems that the problem is still strcmp(). After I commented strcmp() in
>> arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
>> it works well.
>
> Does that help?

It still needs to add 'volatile' to prevent compiler optimizations.
Otherwise,
Tested-by: Zhen Lei <[email protected]>

>
> diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
> index f759d944c449..cdafd67774e0 100644
> --- a/arch/m68k/include/asm/string.h
> +++ b/arch/m68k/include/asm/string.h
> @@ -42,18 +42,19 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
> #define __HAVE_ARCH_STRCMP
> static inline int strcmp(const char *cs, const char *ct)
> {
> - char res;
> + int res = 0, tmp = 0;
>
> asm ("\n"

- asm ("\n"
+ asm volatile ("\n"


> "1: move.b (%0)+,%2\n" /* get *cs */
> - " cmp.b (%1)+,%2\n" /* compare a byte */
> + " move.b (%1)+,%3\n" /* get *ct */
> + " cmp.b %3,%2\n" /* compare a byte */
> " jne 2f\n" /* not equal, break out */
> " tst.b %2\n" /* at end of cs? */
> " jne 1b\n" /* no, keep going */
> " jra 3f\n" /* strings are equal */
> - "2: sub.b -(%1),%2\n" /* *cs - *ct */
> + "2: sub.l %3,%2\n" /* *cs - *ct */
> "3:"
> - : "+a" (cs), "+a" (ct), "=d" (res));
> + : "+a" (cs), "+a" (ct), "+d" (res), "+d" (tmp));
> return res;
> }
> #endif /* CONFIG_COLDFIRE */
>

--
Regards,
Zhen Lei

2022-12-16 14:33:51

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Leizhen (ThunderTown)
> Sent: 16 December 2022 12:02
>
..
> > Moving the m68k version inside lib/string.c makes the test pass, too.
> > So it must be related to the function being inline, and gcc making
> > (incorrect) assumptions...
>
> Yes, it's the compiler's fault. I just replied David Laight:
>
> I added 'volatile' to prevent compiler optimizations, and it's OK now.
>
> diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
> index f759d944c449940..3db81e5a783c72a 100644
> --- a/arch/m68k/include/asm/string.h
> +++ b/arch/m68k/include/asm/string.h
> @@ -42,9 +42,9 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
> #define __HAVE_ARCH_STRCMP
> static inline int strcmp(const char *cs, const char *ct)
> {
> - char res;
> + signed char res;
>
> - asm ("\n"
> + asm volatile ("\n"
> "1: move.b (%0)+,%2\n" /* get *cs */
> " cmp.b (%1)+,%2\n" /* compare a byte */
> " jne 2f\n" /* not equal, break out */

Adding 'volatile' there shouldn't make any real difference.

I'd double-check the asm constraints for the two pointers.
They are modified by the asm, but the caller's variables
must not be changed.

I think that means they need to be normal 'input' parameters
and the result must be in different register (early clobber?).
Currently the pointers are "+r" - which I think means they
are input-output and any caller-supplied variable is
likely to get changed.

David



-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 14:37:08

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, Leizhen (ThunderTown) wrote:

> On 2022/12/16 19:57, Andreas Schwab wrote:
>> On Dez 16 2022, Leizhen (ThunderTown) wrote:
>>
>>> It seems that the problem is still strcmp(). After I commented strcmp() in
>>> arch/m68k/include/asm/string.h, and force it to use the one in lib/string.c,
>>> it works well.
>>
>> Does that help?
>
> It still needs to add 'volatile' to prevent compiler optimizations.

If that makes a difference, then something else is wrong.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 15:24:59

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: David Laight
> Sent: 16 December 2022 13:30
>
> From: Leizhen (ThunderTown)
> > Sent: 16 December 2022 12:02
> >
> ..
> > > Moving the m68k version inside lib/string.c makes the test pass, too.
> > > So it must be related to the function being inline, and gcc making
> > > (incorrect) assumptions...
> >
> > Yes, it's the compiler's fault. I just replied David Laight:
> >
> > I added 'volatile' to prevent compiler optimizations, and it's OK now.
> >
> > diff --git a/arch/m68k/include/asm/string.h b/arch/m68k/include/asm/string.h
> > index f759d944c449940..3db81e5a783c72a 100644
> > --- a/arch/m68k/include/asm/string.h
> > +++ b/arch/m68k/include/asm/string.h
> > @@ -42,9 +42,9 @@ static inline char *strncpy(char *dest, const char *src, size_t n)
> > #define __HAVE_ARCH_STRCMP
> > static inline int strcmp(const char *cs, const char *ct)
> > {
> > - char res;
> > + signed char res;
> >
> > - asm ("\n"
> > + asm volatile ("\n"
> > "1: move.b (%0)+,%2\n" /* get *cs */
> > " cmp.b (%1)+,%2\n" /* compare a byte */
> > " jne 2f\n" /* not equal, break out */
>
> Adding 'volatile' there shouldn't make any real difference.
>
> I'd double-check the asm constraints for the two pointers.
> They are modified by the asm, but the caller's variables
> must not be changed.
>
> I think that means they need to be normal 'input' parameters
> and the result must be in different register (early clobber?).
> Currently the pointers are "+r" - which I think means they
> are input-output and any caller-supplied variable is
> likely to get changed.

Definitely badly broken.
'cs' and 'ct' should be input parameters.
'res' needs to be an early-clobber output parameter "=&r".

Since it is actually a 'static inline' (not just a #define)
then letting cs/ct be changed probably doesn't matter.

But the lack of 'early clobber' will cause grief.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 15:31:30

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Andreas Schwab <[email protected]>
> Sent: 16 December 2022 15:20
>
> On Dez 16 2022, David Laight wrote:
>
> > 'cs' and 'ct' should be input parameters.
>
> They are (and output as well).

Right, but the 'output' values aren't needed and get
discarded because the asm block in inside a static inline.

It could be a recipe just waiting to go wrong.

But I bet the actual problem is the output register
aliasing one of the inputs and then reading from very
low user addresses - I bet they don't fault on m68k.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 16:08:15

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, David Laight wrote:

> 'cs' and 'ct' should be input parameters.

They are (and output as well).

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 16:08:58

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, David Laight wrote:

> Right, but the 'output' values aren't needed and get

Yes, they are, because the inline asm modifies them.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 16:26:29

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Andreas Schwab
> Sent: 16 December 2022 15:54
>
> On Dez 16 2022, David Laight wrote:
>
> > Right, but the 'output' values aren't needed and get
>
> Yes, they are, because the inline asm modifies them.

Ok, my brain hurts, too near christmas.

The other issue is a missing "memory" clobber.
Although I'm not sure why that could matter here.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 16:26:56

by Andreas Schwab

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Dez 16 2022, David Laight wrote:

> The other issue is a missing "memory" clobber.

strcmp is a pure read-only operation.

--
Andreas Schwab, [email protected]
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510 2552 DF73 E780 A9DA AEC1
"And now for something completely different."

2022-12-16 16:47:30

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Andreas Schwab
> Sent: 16 December 2022 16:12
> On Dez 16 2022, David Laight wrote:
>
> > The other issue is a missing "memory" clobber.
>
> strcmp is a pure read-only operation.

Still needs the memory clobber.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 17:44:19

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Fri, 16 Dec 2022 16:32:08 +0000
David Laight <[email protected]> wrote:

> From: Andreas Schwab
> > Sent: 16 December 2022 16:12
> > On Dez 16 2022, David Laight wrote:
> >
> > > The other issue is a missing "memory" clobber.
> >
> > strcmp is a pure read-only operation.
>
> Still needs the memory clobber.

What memory is being modified?

I don't know m68k assembly, but I'm guessing the (%O)+ and the (%1)+ only
modifies the register being used, and no memory is being touched.

-- Steve

2022-12-16 17:46:52

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Steven Rostedt
> Sent: 16 December 2022 16:53
>
> On Fri, 16 Dec 2022 16:32:08 +0000
> David Laight <[email protected]> wrote:
>
> > From: Andreas Schwab
> > > Sent: 16 December 2022 16:12
> > > On Dez 16 2022, David Laight wrote:
> > >
> > > > The other issue is a missing "memory" clobber.
> > >
> > > strcmp is a pure read-only operation.
> >
> > Still needs the memory clobber.
>
> What memory is being modified?
>
> I don't know m68k assembly, but I'm guessing the (%O)+ and the (%1)+ only
> modifies the register being used, and no memory is being touched.

Memory is being read so a clobber is needed to ensure that all pending
writes have been done.
Although, in this case, the memory being read is effectively
read only so nothing should be pending.

But it really does look like something is 'smelly' with the
constraints.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-16 17:49:17

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Fri, 16 Dec 2022 12:19:47 -0500
Steven Rostedt <[email protected]> wrote:

> I assumed that "memory" was for memory unrelated to the input constraints.

Well, it looks like you do need a "memory" barrier.

https://gcc.gnu.org/onlinedocs/gcc/Extended-Asm.html

"memory"

The "memory" clobber tells the compiler that the assembly code
performs memory reads or writes to items other than those listed in
the input and output operands (for example, accessing the memory
pointed to by one of the input parameters). To ensure memory contains
correct values, GCC may need to flush specific register values to
memory before executing the asm. Further, the compiler does not
assume that any values read from memory before an asm remain
unchanged after that asm; it reloads them as needed. Using the
"memory" clobber effectively forms a read/write memory barrier for
the compiler.

As the "(for example, accessing the memory pointed to by one of the input
parameters)" is exactly this case.

-- Steve

2022-12-16 18:13:55

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

On Fri, 16 Dec 2022 16:57:54 +0000
David Laight <[email protected]> wrote:

> > I don't know m68k assembly, but I'm guessing the (%O)+ and the (%1)+ only
> > modifies the register being used, and no memory is being touched.
>
> Memory is being read so a clobber is needed to ensure that all pending
> writes have been done.
> Although, in this case, the memory being read is effectively
> read only so nothing should be

I would think that if the memory being read is the address of what the
input parameters being passed into it are, then the compiler should be
smart enough to know that there's a relation. Especially if the input
parameters are pointers.

I assumed that "memory" was for memory unrelated to the input constraints.

-- Steve

2022-12-16 19:47:05

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Steven Rostedt
> Sent: 16 December 2022 17:38
>
> On Fri, 16 Dec 2022 12:19:47 -0500
> Steven Rostedt <[email protected]> wrote:
>
> > I assumed that "memory" was for memory unrelated to the input constraints.
>
> Well, it looks like you do need a "memory" barrier.
>
> https://gcc.gnu.org/onlinedocs/gcc/Extended-Asm.html
>
> "memory"
>
> The "memory" clobber tells the compiler that the assembly code
> performs memory reads or writes to items other than those listed in
> the input and output operands (for example, accessing the memory
> pointed to by one of the input parameters). To ensure memory contains
> correct values, GCC may need to flush specific register values to
> memory before executing the asm. Further, the compiler does not
> assume that any values read from memory before an asm remain
> unchanged after that asm; it reloads them as needed. Using the
> "memory" clobber effectively forms a read/write memory barrier for
> the compiler.
>
> As the "(for example, accessing the memory pointed to by one of the input
> parameters)" is exactly this case.

Without the memory clobber code like:
int f(const char *s)
{
char c[4] = "abc";
return strcmp(s, c);
}
is very like to get optimised so that c[] is never written.

However, in this case, the strings have all existed for ages.
So that won't be the problem.

It might be obvious what is wrong from the asm output.
Although the binary-chop lookup is suspect I'd also check
that the sorted index is plausible - just tracing the first
20 entries might be enough.
No point peering at the search code if the setup is wrong.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)

2022-12-17 09:33:59

by Zhen Lei

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility



On 2022/12/17 3:27, David Laight wrote:
> From: Steven Rostedt
>> Sent: 16 December 2022 17:38
>>
>> On Fri, 16 Dec 2022 12:19:47 -0500
>> Steven Rostedt <[email protected]> wrote:
>>
>>> I assumed that "memory" was for memory unrelated to the input constraints.
>>
>> Well, it looks like you do need a "memory" barrier.
>>
>> https://gcc.gnu.org/onlinedocs/gcc/Extended-Asm.html
>>
>> "memory"
>>
>> The "memory" clobber tells the compiler that the assembly code
>> performs memory reads or writes to items other than those listed in
>> the input and output operands (for example, accessing the memory
>> pointed to by one of the input parameters). To ensure memory contains
>> correct values, GCC may need to flush specific register values to
>> memory before executing the asm. Further, the compiler does not
>> assume that any values read from memory before an asm remain
>> unchanged after that asm; it reloads them as needed. Using the
>> "memory" clobber effectively forms a read/write memory barrier for
>> the compiler.
>>
>> As the "(for example, accessing the memory pointed to by one of the input
>> parameters)" is exactly this case.
>
> Without the memory clobber code like:
> int f(const char *s)
> {
> char c[4] = "abc";
> return strcmp(s, c);
> }
> is very like to get optimised so that c[] is never written.
>
> However, in this case, the strings have all existed for ages.
> So that won't be the problem.
>
> It might be obvious what is wrong from the asm output.
> Although the binary-chop lookup is suspect I'd also check
> that the sorted index is plausible - just tracing the first
> 20 entries might be enough.
> No point peering at the search code if the setup is wrong.

6.47.2.1 Volatile
GCC’s optimizers sometimes discard asm statements if they determine there is no need for
the output variables. Also, the optimizers may move code out of loops if they believe that
the code will always return the same result (i.e. none of its input values change between
calls). Using the volatile qualifier disables these optimizations.

So it's quite possible (I didn't disassemble vmlinux, because I didn't learn m68k):

//binary search
while (low <= high) {
...
ret = compare_symbol_name(name, namebuf); ----> (1)
if (!ret)
break;
}

low = mid;
while (low) {
...
if (compare_symbol_name(name, namebuf)) ----> (2)
break;
low--;
}

The pointer 'name' and 'namebuf' of (1) and (2) are the same,
so the 'if' statement of (2) maybe omitted by compiler.

By the way, I tried no volatile but with
+ : : "memory");
It also works well.

>
> David
>
> -
> Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
> Registration No: 1397386 (Wales)
>
>
> .
>

--
Regards,
Zhen Lei

2022-12-17 14:31:36

by Geert Uytterhoeven

[permalink] [raw]
Subject: Re: [PATCH v9] kallsyms: Add self-test facility

Hi Zhen,

On Sat, Dec 17, 2022 at 8:32 AM Leizhen (ThunderTown)
<[email protected]> wrote:
> On 2022/12/17 3:27, David Laight wrote:
> > From: Steven Rostedt
> >> Sent: 16 December 2022 17:38
> >>
> >> On Fri, 16 Dec 2022 12:19:47 -0500
> >> Steven Rostedt <[email protected]> wrote:
> >>
> >>> I assumed that "memory" was for memory unrelated to the input constraints.
> >>
> >> Well, it looks like you do need a "memory" barrier.
> >>
> >> https://gcc.gnu.org/onlinedocs/gcc/Extended-Asm.html
> >>
> >> "memory"
> >>
> >> The "memory" clobber tells the compiler that the assembly code
> >> performs memory reads or writes to items other than those listed in
> >> the input and output operands (for example, accessing the memory
> >> pointed to by one of the input parameters). To ensure memory contains
> >> correct values, GCC may need to flush specific register values to
> >> memory before executing the asm. Further, the compiler does not
> >> assume that any values read from memory before an asm remain
> >> unchanged after that asm; it reloads them as needed. Using the
> >> "memory" clobber effectively forms a read/write memory barrier for
> >> the compiler.
> >>
> >> As the "(for example, accessing the memory pointed to by one of the input
> >> parameters)" is exactly this case.
> >
> > Without the memory clobber code like:
> > int f(const char *s)
> > {
> > char c[4] = "abc";
> > return strcmp(s, c);
> > }
> > is very like to get optimised so that c[] is never written.
> >
> > However, in this case, the strings have all existed for ages.
> > So that won't be the problem.
> >
> > It might be obvious what is wrong from the asm output.
> > Although the binary-chop lookup is suspect I'd also check
> > that the sorted index is plausible - just tracing the first
> > 20 entries might be enough.
> > No point peering at the search code if the setup is wrong.
>
> 6.47.2.1 Volatile
> GCC’s optimizers sometimes discard asm statements if they determine there is no need for
> the output variables. Also, the optimizers may move code out of loops if they believe that
> the code will always return the same result (i.e. none of its input values change between
> calls). Using the volatile qualifier disables these optimizations.
>
> So it's quite possible (I didn't disassemble vmlinux, because I didn't learn m68k):

You don't have to disassemble, "make kernel/kallsyms.s" creates
annotated assembler.

> //binary search
> while (low <= high) {
> ...
> ret = compare_symbol_name(name, namebuf); ----> (1)
> if (!ret)
> break;
> }
>
> low = mid;
> while (low) {
> ...
> if (compare_symbol_name(name, namebuf)) ----> (2)
> break;
> low--;
> }
>
> The pointer 'name' and 'namebuf' of (1) and (2) are the same,
> so the 'if' statement of (2) maybe omitted by compiler.

And that is exactly what is happening: there are 3 calls to strcmp()
with the exact same parameters, and gcc omits two of them, because it
assumes it can predict the outcome, as the parameters haven't changed.

Now, why have we never noticed this before? I guess because it is very
uncommon for a function calling strcmp() multiple times with the exact
same pointer parameters. Common users change the pointers before
every call, instead of keeping the pointer, but changing the buffers'
contents the pointers point to.

> By the way, I tried no volatile but with
> + : : "memory");
> It also works well.

Indeed, gcc version 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04) generates the
same code for either adding the volatile or the memory clobber.

Note that strcmp() is the only function in arch/m68k/include/asm/string.h
using inline asm without the volatile keyword. I guess we would
see similar issues with strnlen() (which also doesn't modify memory)
when dropping the volatile.

Gr{oetje,eeting}s,

Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [email protected]

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds

2022-12-17 18:06:55

by David Laight

[permalink] [raw]
Subject: RE: [PATCH v9] kallsyms: Add self-test facility

From: Geert Uytterhoeven
> Sent: 17 December 2022 13:37
...
> > So it's quite possible (I didn't disassemble vmlinux, because I didn't learn m68k):

Pretty easy to read it.

...
> > //binary search
> > while (low <= high) {
> > ...
> > ret = compare_symbol_name(name, namebuf); ----> (1)
> > if (!ret)
> > break;
> > }
> >
> > low = mid;
> > while (low) {
> > ...
> > if (compare_symbol_name(name, namebuf)) ----> (2)
> > break;
> > low--;
> > }
> >
> > The pointer 'name' and 'namebuf' of (1) and (2) are the same,
> > so the 'if' statement of (2) maybe omitted by compiler.
>
> And that is exactly what is happening: there are 3 calls to strcmp()
> with the exact same parameters, and gcc omits two of them, because it
> assumes it can predict the outcome, as the parameters haven't changed.

Additionally if kallsyms_expand_symbol() is inlined all the writes
it does to namebuf[] can get discarded - because they are used.
Which probably causes the entire function to get optimised away.
More code follows - there could easily be nothing left except
the binary chop itself that ensures the loop terminates.

> Now, why have we never noticed this before? I guess because it is very
> uncommon for a function calling strcmp() multiple times with the exact
> same pointer parameters. Common users change the pointers before
> every call, instead of keeping the pointer, but changing the buffers'
> contents the pointers point to.
>
> > By the way, I tried no volatile but with
> > + : : "memory");
> > It also works well.
>
> Indeed, gcc version 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04) generates the
> same code for either adding the volatile or the memory clobber.
>
> Note that strcmp() is the only function in arch/m68k/include/asm/string.h
> using inline asm without the volatile keyword. I guess we would
> see similar issues with strnlen() (which also doesn't modify memory)
> when dropping the volatile.

The 'volatile' ensures that strcmp() doesn't get thrown away.
It doesn't ensure that the writes to namebuf[] aren't optimised away.

Only the memory clobber does that.

So all those asm functions need the memory clobber.
They probably don't need volatile - since the call has
a result.
Indeed since the memory clobber also says 'writes to memory'
it may make the volatile pointless.

I'd also add the 'early clobber' annotation to the result.
It may not matter since the pointers are in-out, but since
the pointer outputs are discarded some 'brain-damaged'
register allocation might assign the same register.

David

-
Registered Address Lakeside, Bramley Road, Mount Farm, Milton Keynes, MK1 1PT, UK
Registration No: 1397386 (Wales)