| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <202212251728.8d0872ff-oliver.sang@intel.com>
Date: Sun, 25 Dec 2022 17:42:50 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Zhen Lei <thunder.leizhen@...wei.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>,
Luis Chamberlain <mcgrof@...nel.org>,
<linux-kernel@...r.kernel.org>
Subject: [linus:master] [kallsyms] 30f3bb0977:
BUG:sleeping_function_called_from_invalid_context_at_kernel/kallsyms.c
Greeting,
FYI, we noticed BUG:sleeping_function_called_from_invalid_context_at_kernel/kallsyms.c due to commit (built with gcc-11):
commit: 30f3bb09778de64ef9f23fb4bb5f868c4728a071 ("kallsyms: Add self-test facility")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linux-next/master e45fb347b630ee76482fe938ba76cf8eab811290]
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Link: https://lore.kernel.org/oe-lkp/202212251728.8d0872ff-oliver.sang@intel.com
[ 296.591291][ T94] BUG: sleeping function called from invalid context at kernel/kallsyms.c:305
[ 296.593681][ T94] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 94, name: kallsyms_test
[ 296.596102][ T94] preempt_count: 0, expected: 0
[ 296.598141][ T94] no locks held by kallsyms_test/94.
[ 296.600262][ T94] irq event stamp: 3417486
[ 296.602249][ T94] hardirqs last enabled at (3417485): __up_console_sem (printk.c:?)
[ 296.604738][ T94] hardirqs last disabled at (3417486): test_perf_kallsyms_on_each_symbol (kallsyms_selftest.c:?)
[ 296.607395][ T94] softirqs last enabled at (3417468): __do_softirq (??:?)
[ 296.609876][ T94] softirqs last disabled at (3417445): call_on_stack (irq_32.c:?)
[ 296.612357][ T94] CPU: 0 PID: 94 Comm: kallsyms_test Not tainted 6.1.0-rc4-00305-g30f3bb09778d #1 3b214fee31cbe937ecaf44a673d9d82d04570a37
[ 296.615262][ T94] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 296.617998][ T94] Call Trace:
[ 296.620022][ T94] dump_stack_lvl (??:?)
[ 296.622163][ T94] dump_stack (??:?)
[ 296.624205][ T94] __might_resched (??:?)
[ 296.626329][ T94] ? lookup_name (kallsyms_selftest.c:?)
[ 296.628326][ T94] kallsyms_on_each_symbol (??:?)
[ 296.630531][ T94] ? desc_read (printk_ringbuffer.c:?)
[ 296.632566][ T94] ? desc_read_finalized_seq (printk_ringbuffer.c:?)
[ 296.634809][ T94] ? mark_lock+0x2f/0x10f
[ 296.636894][ T94] ? lock_is_held (signal.c:?)
[ 296.638951][ T94] ? rcu_read_lock_any_held (??:?)
[ 296.641070][ T94] ? lookup_chain_cache (lockdep.c:?)
[ 296.642990][ T94] ? validate_chain (lockdep.c:?)
[ 296.644899][ T94] ? kvm_sched_clock_read (kvmclock.c:?)
[ 296.646928][ T94] ? desc_read (printk_ringbuffer.c:?)
[ 296.648772][ T94] ? desc_read_finalized_seq (printk_ringbuffer.c:?)
[ 296.650719][ T94] ? prb_read (printk_ringbuffer.c:?)
[ 296.652544][ T94] ? desc_read (printk_ringbuffer.c:?)
[ 296.654362][ T94] ? _prb_read_valid (printk_ringbuffer.c:?)
[ 296.656271][ T94] ? prb_read_valid (??:?)
[ 296.658113][ T94] ? console_unlock (??:?)
[ 296.660000][ T94] ? irq_work_queue (??:?)
[ 296.661824][ T94] ? __wake_up_klogd+0x30/0x40
[ 296.663825][ T94] ? wake_up_klogd (??:?)
[ 296.665652][ T94] ? vprintk_emit (??:?)
[ 296.667406][ T94] ? vprintk_default (??:?)
[ 296.669131][ T94] ? vprintk (??:?)
[ 296.670713][ T94] ? kvm_clock_read (kvmclock.c:?)
[ 296.672390][ T94] test_perf_kallsyms_on_each_symbol (kallsyms_selftest.c:?)
[ 296.674225][ T94] test_entry (kallsyms_selftest.c:?)
[ 296.675660][ T94] kthread (kthread.c:?)
[ 296.677142][ T94] ? find_symbol (kallsyms_selftest.c:?)
[ 296.678689][ T94] ? kthread_complete_and_exit (kthread.c:?)
[ 296.680299][ T94] ret_from_fork (??:?)
[ 296.808624][ T94] ------------[ cut here ]------------
[ 296.810326][ T94] raw_local_irq_restore() called with IRQs enabled
[ 296.812238][ T94] WARNING: CPU: 0 PID: 94 at kernel/locking/irqflag-debug.c:10 warn_bogus_irq_restore (??:?)
[ 296.814348][ T94] Modules linked in: input_leds crc32_pclmul floppy evdev qemu_fw_cfg
[ 296.816465][ T94] CPU: 0 PID: 94 Comm: kallsyms_test Tainted: G W 6.1.0-rc4-00305-g30f3bb09778d #1 3b214fee31cbe937ecaf44a673d9d82d04570a37
[ 296.819114][ T94] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 296.821303][ T94] EIP: warn_bogus_irq_restore (??:?)
[ 296.823022][ T94] Code: 00 10 00 00 31 d2 31 c9 e9 5b b4 00 00 80 3d 1f 8c b0 c2 00 75 1f 55 89 e5 68 66 c0 1f c2 c6 05 1f 8c b0 c2 01 e8 c7 68 fe ff <0f> 0b 58 c9 31 c0 e9 33 b4 00 00 31 c0 e9 2c b4 00 00 55 89 e5 56
All code
========
0: 00 10 add %dl,(%rax)
2: 00 00 add %al,(%rax)
4: 31 d2 xor %edx,%edx
6: 31 c9 xor %ecx,%ecx
8: e9 5b b4 00 00 jmpq 0xb468
d: 80 3d 1f 8c b0 c2 00 cmpb $0x0,-0x3d4f73e1(%rip) # 0xffffffffc2b08c33
14: 75 1f jne 0x35
16: 55 push %rbp
17: 89 e5 mov %esp,%ebp
19: 68 66 c0 1f c2 pushq $0xffffffffc21fc066
1e: c6 05 1f 8c b0 c2 01 movb $0x1,-0x3d4f73e1(%rip) # 0xffffffffc2b08c44
25: e8 c7 68 fe ff callq 0xfffffffffffe68f1
2a:* 0f 0b ud2 <-- trapping instruction
2c: 58 pop %rax
2d: c9 leaveq
2e: 31 c0 xor %eax,%eax
30: e9 33 b4 00 00 jmpq 0xb468
35: 31 c0 xor %eax,%eax
37: e9 2c b4 00 00 jmpq 0xb468
3c: 55 push %rbp
3d: 89 e5 mov %esp,%ebp
3f: 56 push %rsi
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 58 pop %rax
3: c9 leaveq
4: 31 c0 xor %eax,%eax
6: e9 33 b4 00 00 jmpq 0xb43e
b: 31 c0 xor %eax,%eax
d: e9 2c b4 00 00 jmpq 0xb43e
12: 55 push %rbp
13: 89 e5 mov %esp,%ebp
15: 56 push %rsi
[ 296.827435][ T94] EAX: 00000000 EBX: 00000200 ECX: 00000000 EDX: 00000000
[ 296.829481][ T94] ESI: 1ba482a7 EDI: 00000045 EBP: ec7b5e44 ESP: ec7b5e40
[ 296.831524][ T94] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068 EFLAGS: 00010246
[ 296.833568][ T94] CR0: 80050033 CR2: b7f9b178 CR3: 2b828000 CR4: 00040690
[ 296.835567][ T94] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 296.837569][ T94] DR6: fffe0ff0 DR7: 00000400
[ 296.839224][ T94] Call Trace:
[ 296.840731][ T94] test_perf_kallsyms_on_each_symbol (kallsyms_selftest.c:?)
[ 296.842731][ T94] test_entry (kallsyms_selftest.c:?)
[ 296.844314][ T94] kthread (kthread.c:?)
[ 296.845867][ T94] ? find_symbol (kallsyms_selftest.c:?)
[ 296.847545][ T94] ? kthread_complete_and_exit (kthread.c:?)
[ 296.849401][ T94] ret_from_fork (??:?)
[ 296.851088][ T94] irq event stamp: 3417903
[ 296.852761][ T94] hardirqs last enabled at (3417915): __up_console_sem (printk.c:?)
[ 296.854950][ T94] hardirqs last disabled at (3417928): __up_console_sem (printk.c:?)
[ 296.856940][ T94] softirqs last enabled at (3417888): __do_softirq (??:?)
[ 296.859047][ T94] softirqs last disabled at (3417879): call_on_stack (irq_32.c:?)
[ 296.861227][ T94] ---[ end trace 0000000000000000 ]---
[ 296.863011][ T94] kallsyms_selftest: kallsyms_on_each_symbol() traverse all: 217308966 ns
[ 296.865205][ T94] kallsyms_selftest: kallsyms_on_each_match_symbol() traverse all: 30537 ns
[ 296.867362][ T94] kallsyms_selftest: finish
[ 298.261272][ T39] rcu-torture: rcu_torture_read_exit: Start of episode
[ 302.550643][ T39] rcu-torture: rcu_torture_read_exit: End of episode
[ 307.941285][ T35] rcu-torture: rtc: c337bcc4 ver: 9533 tfle: 0 rta: 9534 rtaf: 0 rtf: 9524 rtmbe: 0 rtmbkf: 0/0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 1612 barrier: 0/0:0 read-exits: 272 nocb-toggles: 0:0
[ 307.946249][ T35] rcu-torture: Reader Pipe: 697782 0 0 0 0 0 0 0 0 0 0
[ 307.948593][ T35] rcu-torture: Reader Batch: 697782 0 0 0 0 0 0 0 0 0 0
[ 307.950927][ T35] rcu-torture: Free-Block Circulation: 9533 9532 9531 9530 9529 9528 9527 9526 9525 9524 0
[ 316.367995][ T39] rcu-torture: rcu_torture_read_exit: Start of episode
[ 316.383065][ T39] rcu-torture: rcu_torture_read_exit: End of episode
[ 329.674553][ T39] rcu-torture: rcu_torture_read_exit: Start of episode
[ 329.688244][ T39] rcu-torture: rcu_torture_read_exit: End of episode
[ 343.088028][ T39] rcu-torture: rcu_torture_read_exit: Start of episode
[ 343.105552][ T39] rcu-torture: rcu_torture_read_exit: End of episode
[ 354.021259][ T38] rcu_torture_fwd_prog n_max_cbs: 1667
[ 354.023716][ T38] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 354.026110][ T38] rcu_torture_fwd_prog_cr: Starting forward-progress test 0
[ 354.049763][ T38] rcu_torture_fwd_prog_cr: Waiting for CBs: rcu_barrier+0x0/0x32() 0
[ 354.061725][ T38] rcu_torture_fwd_prog_cr Duration 6 barrier: 4 pending 104 n_launders: 1480 n_launders_sa: 103 n_max_gps: 100 n_max_cbs: 1350 cver 0 gps 0
[ 354.065954][ T38] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 11 jiffies): 1s/10: 2830:0
Kboot worker: lkp-worker64
Elapsed time: 360
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-meta-259.cgz
-m 16384
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-device i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-meta-259::dhcp
root=/dev/ram0
RESULT_ROOT=/result/boot/300/vm-snb/debian-11.1-i386-20220923.cgz/i386-randconfig-a001-20221219/gcc-11/30f3bb09778de64ef9f23fb4bb5f868c4728a071/3
BOOT_IMAGE=/pkg/linux/i386-randconfig-a001-20221219/gcc-11/30f3bb09778de64ef9f23fb4bb5f868c4728a071/vmlinuz-6.1.0-rc4-00305-g30f3bb09778d
branch=linus/master
job=/job-script
user=lkp
ARCH=i386
kconfig=i386-randconfig-a001-20221219
commit=30f3bb09778de64ef9f23fb4bb5f868c4728a071
vmalloc=256M
initramfs_async=0
page_owner=on
initcall_debug
max_uptime=600
result_service=tmpfs
selinux=0
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
drbd.minor_count=8
systemd.log_level=err
ignore_loglevel
console=tty0
earlyprintk=ttyS0,115200
console=ttyS0,115200
vga=normal
rw
rcuperf.shutdown=0
watchdog_thresh=240
)
"${kvm[@]}" -append "${append[*]}"
To reproduce:
# build kernel
cd linux
cp config-6.1.0-rc4-00305-g30f3bb09778d .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=i386 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=i386 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests
View attachment "config-6.1.0-rc4-00305-g30f3bb09778d" of type "text/plain" (164338 bytes)
View attachment "job-script" of type "text/plain" (5015 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (41788 bytes)
Powered by blists - more mailing lists