2022-11-16 15:53:59

by kernel test robot

[permalink] [raw]
Subject: [mcgrof:20221115-firmware_loader-fixes] [firmware_loader] 3960520a85: WARNING:at_lib/kobject.c:#kobject_put

Greeting,

FYI, we noticed WARNING:at_lib/kobject.c:#kobject_put due to commit (built with gcc-11):

commit: 3960520a8525632aeff91e16cae54799308d8e92 ("firmware_loader: refcount device early on request_firmware_nowait()")
https://git.kernel.org/cgit/linux/kernel/git/mcgrof/linux.git 20221115-firmware_loader-fixes

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):


[ 205.157342][ T22] ------------[ cut here ]------------
[ 205.158177][ T1] calling latency_fsnotify_init+0x0/0x4f @ 1
[ 205.159678][ T22] WARNING: CPU: 1 PID: 22 at lib/kobject.c:718 kobject_put (lib/kobject.c:718)
[ 205.160221][ T1] initcall latency_fsnotify_init+0x0/0x4f returned 0 after 197 usecs
[ 205.160906][ T22] Modules linked in:
[ 205.162359][ T1] calling trace_eval_sync+0x0/0x2c @ 1
[ 205.163537][ T22] CPU: 1 PID: 22 Comm: kworker/1:0 Not tainted 6.1.0-rc5-00002-g3960520a8525 #2
[ 205.164785][ T1] initcall trace_eval_sync+0x0/0x2c returned 0 after 28 usecs
[ 205.165319][ T22] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 205.166132][ T1] calling late_trace_init+0x0/0x108 @ 1
[ 205.167376][ T22] Workqueue: events request_firmware_work_func
[ 205.168434][ T1] initcall late_trace_init+0x0/0x108 returned 0 after 1 usecs
[ 205.169797][ T22]
[ 205.169807][ T22] RIP: 0010:kobject_put (lib/kobject.c:718)
[ 205.170573][ T1] calling acpi_gpio_handle_deferred_request_irqs+0x0/0x9f @ 1
[ 205.171433][ T22] Code: fe 5b 5d 41 5c c3 cc cc cc cc e8 f0 6b 8d fe 48 89 ef e8 98 d5 a1 fe 48 8b 75 00 48 89 ea 48 c7 c7 68 c3 49 83 e8 99 81 05 00 <0f> 0b e9 71 ff ff ff e8 c9 6b 8d fe 48 89 ef e8 c1 fc ff ff e8 bc
All code
========
0: fe (bad)
1: 5b pop %rbx
2: 5d pop %rbp
3: 41 5c pop %r12
5: c3 retq
6: cc int3
7: cc int3
8: cc int3
9: cc int3
a: e8 f0 6b 8d fe callq 0xfffffffffe8d6bff
f: 48 89 ef mov %rbp,%rdi
12: e8 98 d5 a1 fe callq 0xfffffffffea1d5af
17: 48 8b 75 00 mov 0x0(%rbp),%rsi
1b: 48 89 ea mov %rbp,%rdx
1e: 48 c7 c7 68 c3 49 83 mov $0xffffffff8349c368,%rdi
25: e8 99 81 05 00 callq 0x581c3
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 71 ff ff ff jmpq 0xffffffffffffffa2
31: e8 c9 6b 8d fe callq 0xfffffffffe8d6bff
36: 48 89 ef mov %rbp,%rdi
39: e8 c1 fc ff ff callq 0xfffffffffffffcff
3e: e8 .byte 0xe8
3f: bc .byte 0xbc

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 71 ff ff ff jmpq 0xffffffffffffff78
7: e8 c9 6b 8d fe callq 0xfffffffffe8d6bd5
c: 48 89 ef mov %rbp,%rdi
f: e8 c1 fc ff ff callq 0xfffffffffffffcd5
14: e8 .byte 0xe8
15: bc .byte 0xbc
[ 205.172785][ T1] initcall acpi_gpio_handle_deferred_request_irqs+0x0/0x9f returned 0 after 35 usecs
[ 205.173090][ T22] RSP: 0018:ffffc900000c3d88 EFLAGS: 00010282
[ 205.173756][ T1] calling fb_logo_late_init+0x0/0x24 @ 1
[ 205.174776][ T22]
[ 205.174785][ T22] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 205.177429][ T1] initcall fb_logo_late_init+0x0/0x24 returned 0 after 0 usecs
[ 205.177548][ T1] calling clk_disable_unused+0x0/0x1c0 @ 1
[ 205.177648][ T1] initcall clk_disable_unused+0x0/0x1c0 returned 0 after 2 usecs
[ 205.177692][ T1] calling balloon_wait_finish+0x0/0x21e @ 1
[ 205.177736][ T1] initcall balloon_wait_finish+0x0/0x21e returned -19 after 0 usecs
[ 205.201359][ T22] RDX: ffff888100a7e500 RSI: ffffffff811d7431 RDI: ffffffff83fda738
[ 205.203075][ T22] RBP: ffff88810475f6c0 R08: ffffffff84e05f08 R09: 0000000000000000
[ 205.204515][ T22] R10: 0000000000000004 R11: 0001ffffffffffff R12: ffff88810475f268
[ 205.205797][ T22] R13: ffffffff827acd50 R14: ffff88811d99b838 R15: ffff88842fd2b680
[ 205.207103][ T22] FS: 0000000000000000(0000) GS:ffff88842fd00000(0000) knlGS:0000000000000000
[ 205.208538][ T22] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 205.209557][ T22] CR2: 00000000f7f70000 CR3: 0000000003c0a000 CR4: 00000000000406e0
[ 205.211043][ T22] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 205.212356][ T22] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 205.213633][ T22] Call Trace:
[ 205.214314][ T22] <TASK>
[ 205.214945][ T22] put_device (drivers/base/core.c:3625)
[ 205.215685][ T22] request_firmware_work_func (drivers/base/firmware_loader/main.c:1113)
[ 205.216703][ T22] process_one_work (kernel/workqueue.c:2294)
[ 205.217556][ T22] worker_thread (include/linux/list.h:292 kernel/workqueue.c:2437)
[ 205.218380][ T22] ? process_one_work (kernel/workqueue.c:2379)
[ 205.219228][ T22] kthread (kernel/kthread.c:376)
[ 205.220010][ T22] ? kthread_complete_and_exit (kernel/kthread.c:331)
[ 205.220979][ T22] ret_from_fork (arch/x86/entry/entry_64.S:312)
[ 205.221852][ T22] </TASK>
[ 205.222475][ T22] ---[ end trace 0000000000000000 ]---


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <[email protected]>
| Link: https://lore.kernel.org/oe-lkp/[email protected]


To reproduce:

# build kernel
cd linux
cp config-6.1.0-rc5-00002-g3960520a8525 .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 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://01.org/lkp


Attachments:
(No filename) (6.38 kB)
config-6.1.0-rc5-00002-g3960520a8525 (186.42 kB)
job-script (4.67 kB)
dmesg.xz (28.09 kB)
Download all attachments