On Tue 2022-12-20 08:15:40, Christophe Leroy wrote:

Le 20/12/2022 à 07:39, Zhen Lei a écrit :

quoted

[T58] BUG: sleeping function called from invalid context at kernel/kallsyms.c:305
[T58] in_atomic(): 0, irqs_disabled(): 128, non_block: 0, pid: 58, name: kallsyms_test
[T58] preempt_count: 0, expected: 0
[T58] RCU nest depth: 0, expected: 0
[T58] no locks held by kallsyms_test/58.
[T58] irq event stamp: 18899904
[T58] hardirqs last enabled at (18899903): finish_task_switch.isra.0 (core.c:?)
[T58] hardirqs last disabled at (18899904): test_perf_kallsyms_on_each_symbol (kallsyms_selftest.c:?)
[T58] softirqs last enabled at (18899886): __do_softirq (??:?)
[T58] softirqs last disabled at (18899879): ____do_softirq (irq.c:?)
[T58] CPU: 0 PID: 58 Comm: kallsyms_test Tainted: G T  6.1.0-next-20221215 #2
[T58] Hardware name: linux,dummy-virt (DT)
[T58] Call trace:
[T58] dump_backtrace (??:?)
[T58] show_stack (??:?)
[T58] dump_stack_lvl (??:?)
[T58] dump_stack (??:?)
[T58] __might_resched (??:?)
[T58] kallsyms_on_each_symbol (??:?)
[T58] test_perf_kallsyms_on_each_symbol (kallsyms_selftest.c:?)
[T58] test_entry (kallsyms_selftest.c:?)
[T58] kthread (kthread.c:?)
[T58] ret_from_fork (??:?)
[T58] kallsyms_selftest: kallsyms_on_each_symbol() traverse all: 5744310840 ns
[T58] kallsyms_selftest: kallsyms_on_each_match_symbol() traverse all: 1164580 ns
[T58] kallsyms_selftest: finish

Functions kallsyms_on_each_symbol() and kallsyms_on_each_match_symbol()
call the user-registered hook function for each symbol that meets the
requirements. Because it is uncertain how long that hook function will
execute, they call cond_resched() to avoid consuming CPU resources for a
long time. However, irqs need to be disabled during the performance test
to ensure the accuracy of test data. Because the performance test hook is
very clear, very simple function, let's do not call cond_resched() when
CONFIG_KALLSYMS_SELFTEST=y.

I don't think it is appropriate to change the behaviour of a core 
function based on whether a compile time option related to tests is 
selected or not, because you will change the behaviour for all users, 
not only for the tests.

I agree. This is very bad idea. It would change the behavior for
the entire system.

If the problem is that IRQs are disabled, maybe the solution is

	if (!irqs_disabled())
		cond_resched();

Or try to disable the call to cond_resched() in a way or another during 
the run of selftests.

If I get it correctly, the problem is this code in kernel/kallsyms_selftest.c:

static int lookup_name(void *data, const char *name, struct module *mod, unsigned long addr)
{
[...]
	local_irq_save(flags);
	t0 = sched_clock();
	(void)kallsyms_lookup_name(name);
	t1 = sched_clock();
	local_irq_restore(flags);
[...]

and IRQs are disabled to measure the time spent in this function
without interruption and rescheduling.

I am sure that there are better ways how to measure the time.
Even the "time" command in userspace is able to show time how much CPU
time a command used.

I am not familiar with it. But task_cputime() in
kernel/sched/cputime.c looks promising. And there must be
the interface how the user space get this information.
Some is available via /proc/<PID>/... I am not sure
if there is a syscall.

Best Regards,
Petr