2022-08-21 13:59:17

by kernel test robot

[permalink] [raw]
Subject: [lib/dump_stack] 38a12ad69d: BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/rwsem.c


Greeting,

FYI, we noticed the following commit (built with gcc-11):

commit: 38a12ad69d86f801fac544e6e50cca2a0a8b040b ("lib/dump_stack: add dump_stack_print_cmdline() and wire up in dump_stack_print_info()")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: trinity
version: trinity-static-x86_64-x86_64-1c734c75-1_2020-01-06
with following parameters:

runtime: 300s
group: group-00

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


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 <[email protected]>


[ 85.432613][ T3396] BUG: KCSAN: data-race in __d_add / __d_add
[ 85.433883][ T3396]
[ 85.434366][ T3396] write (marked) to 0xffff888100411fe8 of 4 bytes by task 3397 on cpu 0:
[ 85.435783][ T3396] __d_add (fs/dcache.c:2594 fs/dcache.c:2779)
[ 85.436597][ T3396] d_add (fs/dcache.c:2801)
[ 85.437344][ T3396] simple_lookup (fs/libfs.c:76 fs/libfs.c:69)
[ 85.438231][ T3396] lookup_open+0x400/0x9c0
[ 85.439214][ T3396] open_last_lookups (fs/namei.c:3482)
[ 85.440097][ T3396] path_openat (fs/namei.c:3688 (discriminator 1))
[ 85.441034][ T3396] do_filp_open (fs/namei.c:3718)
[ 85.441929][ T3396] do_sys_openat2 (fs/open.c:1312)
[ 85.442778][ T3396] __x64_sys_openat (fs/open.c:1338)
[ 85.443664][ T3396] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 85.444522][ T3396] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 85.446278][ T3396]
[ 85.446735][ T3396] read to 0xffff888100411fe8 of 4 bytes by task 3396 on cpu 1:
[ 85.448192][ T3396] __d_add (fs/dcache.c:2584 fs/dcache.c:2766)
[ 85.448949][ T3396] d_add (fs/dcache.c:2801)
[ 85.449661][ T3396] simple_lookup (fs/libfs.c:76 fs/libfs.c:69)
[ 85.462985][ T3396] __lookup_slow (include/linux/dcache.h:358 include/linux/dcache.h:363 fs/namei.c:1686)
[ 85.478814][ T3396] walk_component (include/linux/fs.h:771 fs/namei.c:1703 fs/namei.c:1993)
[ 85.491602][ T3396] link_path_walk+0x4b9/0x830
[ 85.504683][ T3396] path_openat (fs/namei.c:3687 fs/namei.c:3687)
[ 85.517679][ T3396] do_filp_open (fs/namei.c:3718)
[ 85.530891][ T3396] do_sys_openat2 (fs/open.c:1312)
[ 85.543268][ T3396] __x64_sys_openat (fs/open.c:1338)
[ 85.555899][ T3396] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 85.568696][ T3396] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 85.583627][ T3396]
[ 85.597341][ T3396] value changed: 0x0000c04d -> 0x0000c04e
[ 85.609190][ T3396]
[ 85.624644][ T3396] Reported by Kernel Concurrency Sanitizer on:
[ 85.636543][ T3396] CPU: 1 PID: 3396 Comm: md5sum Not tainted 6.0.0-rc1-00030-g38a12ad69d86 #1
[ 85.649959][ T3396] BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1521
[ 85.664326][ T3396] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 3396, name: md5sum
[ 85.679581][ T3396] preempt_count: 2, expected: 0
[ 85.691944][ T3396] CPU: 1 PID: 3396 Comm: md5sum Not tainted 6.0.0-rc1-00030-g38a12ad69d86 #1
[ 85.707643][ T3396] md5sum[3396] cmdline: md5sum
[ 85.719880][ T3396] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 85.732840][ T3396] Call Trace:
[ 85.745164][ T3396] <TASK>
[ 85.760123][ T3396] dump_stack_lvl (lib/dump_stack.c:141 (discriminator 1))
[ 85.772205][ T3396] dump_stack (lib/dump_stack.c:148)
[ 85.783949][ T3396] __might_resched.cold (kernel/sched/core.c:9893)
[ 85.796594][ T3396] down_read_killable (kernel/locking/rwsem.c:1521)
[ 85.808427][ T3396] ? desc_read_finalized_seq (kernel/printk/printk_ringbuffer.c:1788)
[ 85.822620][ T3396] __access_remote_vm (include/linux/mmap_lock.h:126 mm/memory.c:5439)
[ 85.837807][ T3396] ? desc_read (kernel/printk/printk_ringbuffer.c:536)
[ 85.849076][ T3396] access_remote_vm (mm/memory.c:5511)
[ 85.862938][ T3396] get_mm_cmdline+0x179/0x500
[ 85.878072][ T3396] ? write_comp_data (kernel/kcov.c:229)
[ 85.888643][ T3396] get_task_cmdline_kernel (fs/proc/base.c:367 fs/proc/base.c:367)
[ 85.899354][ T3396] dump_stack_print_cmdline (lib/dump_stack.c:78 (discriminator 1))
[ 85.910049][ T3396] dump_stack_print_info (lib/dump_stack.c:105 lib/dump_stack.c:97)
[ 85.920667][ T3396] ? __d_add (fs/dcache.c:2594 fs/dcache.c:2779)
[ 85.931191][ T3396] print_report.cold (kernel/kcsan/report.c:493)
[ 85.941628][ T3396] ? __d_add (fs/dcache.c:2594 fs/dcache.c:2779)
[ 85.956243][ T3396] ? kcsan_report_known_origin (kernel/kcsan/report.c:693)
[ 85.967078][ T3396] ? kcsan_setup_watchpoint (kernel/kcsan/core.c:667)
[ 85.977766][ T3396] ? __d_add (fs/dcache.c:2584 fs/dcache.c:2766)
[ 85.988428][ T3396] ? d_add (fs/dcache.c:2801)
[ 85.998787][ T3396] ? simple_lookup (fs/libfs.c:76 fs/libfs.c:69)
[ 86.009466][ T3396] ? __lookup_slow (include/linux/dcache.h:358 include/linux/dcache.h:363 fs/namei.c:1686)
[ 86.020166][ T3396] ? walk_component (include/linux/fs.h:771 fs/namei.c:1703 fs/namei.c:1993)
[ 86.034736][ T3396] ? link_path_walk+0x4b9/0x830
[ 86.047554][ T3396] ? path_openat (fs/namei.c:3687 fs/namei.c:3687)
[ 86.057856][ T3396] ? do_filp_open (fs/namei.c:3718)
[ 86.068332][ T3396] ? do_sys_openat2 (fs/open.c:1312)
[ 86.078592][ T3396] ? __x64_sys_openat (fs/open.c:1338)
[ 86.089065][ T3396] ? do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 86.100363][ T3396] ? entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 86.110794][ T3396] ? rb_insert_color (lib/rbtree.c:110 lib/rbtree.c:436)
[ 86.121069][ T3396] ? __list_add_valid (lib/list_debug.c:30 (discriminator 8))
[ 86.131589][ T3396] ? __create_object+0x216/0x3c0
[ 86.144410][ T3396] kcsan_report_known_origin (kernel/kcsan/report.c:693)
[ 86.159807][ T3396] kcsan_setup_watchpoint (kernel/kcsan/core.c:667)
[ 86.170312][ T3396] ? __d_add (fs/dcache.c:2584 fs/dcache.c:2766)
[ 86.180749][ T3396] __d_add (fs/dcache.c:2584 fs/dcache.c:2766)
[ 86.191132][ T3396] ? write_comp_data (kernel/kcov.c:229)
[ 86.203311][ T3396] d_add (fs/dcache.c:2801)
[ 86.216293][ T3396] simple_lookup (fs/libfs.c:76 fs/libfs.c:69)
[ 86.226457][ T3396] __lookup_slow (include/linux/dcache.h:358 include/linux/dcache.h:363 fs/namei.c:1686)
[ 86.236465][ T3396] walk_component (include/linux/fs.h:771 fs/namei.c:1703 fs/namei.c:1993)
[ 86.246249][ T3396] link_path_walk+0x4b9/0x830
[ 86.260069][ T3396] path_openat (fs/namei.c:3687 fs/namei.c:3687)
[ 86.269582][ T3396] ? write_comp_data (kernel/kcov.c:229)
[ 86.279972][ T3396] do_filp_open (fs/namei.c:3718)
[ 86.292414][ T3396] ? _find_next_bit (lib/find_bit.c:70)
[ 86.302682][ T3396] ? write_comp_data (kernel/kcov.c:229)
[ 86.311257][ T3396] ? alloc_fd (arch/x86/include/asm/paravirt.h:596 (discriminator 10) arch/x86/include/asm/qspinlock.h:57 (discriminator 10) include/linux/spinlock.h:202 (discriminator 10) include/linux/spinlock_api_smp.h:142 (discriminator 10) include/linux/spinlock.h:389 (discriminator 10) fs/file.c:553 (discriminator 10))
[ 86.319885][ T3396] do_sys_openat2 (fs/open.c:1312)
[ 86.328559][ T3396] ? blkcg_maybe_throttle_current (block/blk-cgroup.c:1835)
[ 86.337698][ T3396] __x64_sys_openat (fs/open.c:1338)
[ 86.346690][ T3396] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 86.357529][ T3396] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:120)
[ 86.366643][ T3396] RIP: 0033:0x7fdd4c70365d
[ 86.375410][ T3396] Code: 48 89 54 24 e0 41 83 e2 40 75 32 89 f0 25 00 00 41 00 3d 00 00 41 00 74 24 89 f2 b8 01 01 00 00 48 89 fe bf 9c ff ff ff 0f 05 <48> 3d 00 f0 ff ff 77 33 c3 66 2e 0f 1f 84 00 00 00 00 00 48 8d 44
All code
========
0: 48 89 54 24 e0 mov %rdx,-0x20(%rsp)
5: 41 83 e2 40 and $0x40,%r10d
9: 75 32 jne 0x3d
b: 89 f0 mov %esi,%eax
d: 25 00 00 41 00 and $0x410000,%eax
12: 3d 00 00 41 00 cmp $0x410000,%eax
17: 74 24 je 0x3d
19: 89 f2 mov %esi,%edx
1b: b8 01 01 00 00 mov $0x101,%eax
20: 48 89 fe mov %rdi,%rsi
23: bf 9c ff ff ff mov $0xffffff9c,%edi
28: 0f 05 syscall
2a:* 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax <-- trapping instruction
30: 77 33 ja 0x65
32: c3 retq
33: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
3a: 00 00 00
3d: 48 rex.W
3e: 8d .byte 0x8d
3f: 44 rex.R

Code starting with the faulting instruction
===========================================
0: 48 3d 00 f0 ff ff cmp $0xfffffffffffff000,%rax
6: 77 33 ja 0x3b
8: c3 retq
9: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
10: 00 00 00
13: 48 rex.W
14: 8d .byte 0x8d
15: 44 rex.R
[ 86.397505][ T3396] RSP: 002b:00007ffc1d091f68 EFLAGS: 00000287 ORIG_RAX: 0000000000000101
[ 86.410198][ T3396] RAX: ffffffffffffffda RBX: 0000000000000011 RCX: 00007fdd4c70365d
[ 86.420956][ T3396] RDX: 0000000000080000 RSI: 00007ffc1d092000 RDI: 00000000ffffff9c
[ 86.432607][ T3396] RBP: 00007ffc1d091fe0 R08: 0000000000000000 R09: 00007ffc1d0921ff
[ 86.443609][ T3396] R10: 0000000000000000 R11: 0000000000000287 R12: 00007ffc1d092210
[ 86.456723][ T3396] R13: 0000000000000006 R14: 00007ffc1d0921ff R15: 0000000000000000
[ 86.469996][ T3396] </TASK>
[ 86.480303][ T3396] md5sum[3396] cmdline: md5sum
[ 86.493511][ T3396] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 86.508870][ T3396] ==================================================================
[ 104.056829][ T3700] sctp: Hash tables configured (bind 256/256)
[ 104.085093][ T3645] trinity-main uses obsolete (PF_INET,SOCK_PACKET)
[ 104.297267][ T3716] NET: Registered PF_ATMPVC protocol family
[ 104.327671][ T3716] NET: Registered PF_ATMSVC protocol family
[ 104.709220][ T3728] Loading iSCSI transport class v2.0-870.
[ 105.546910][ T3770] can: controller area network core
[ 105.572749][ T3770] NET: Registered PF_CAN protocol family
[ 105.629961][ T3771] can: raw protocol
[ 105.687681][ T3772] can: broadcast manager protocol
[ 105.797817][ T3776] Bluetooth: RFCOMM TTY layer initialized
[ 105.818963][ T3776] Bluetooth: RFCOMM socket layer initialized
[ 105.843680][ T3776] Bluetooth: RFCOMM ver 1.11
[ 105.906851][ T3778] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 105.927252][ T3778] Bluetooth: BNEP filters: protocol multicast
[ 105.949430][ T3778] Bluetooth: BNEP socket layer initialized
[ 106.020379][ T3780] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[ 106.041721][ T3780] Bluetooth: HIDP socket layer initialized
[ 106.405731][ T3818] VFS: Warning: trinity-c7 using old stat() call. Recompile your binary.
[ 106.441679][ T3818] raw_sendmsg: trinity-c7 forgot to set AF_INET. Fix it!
[ 106.485818][ T3818] Zero length message leads to an empty skb
[ 106.588164][ T3819] Guest personality initialized and is inactive
[ 106.614660][ T3819] VMCI host device registered (name=vmci, major=10, minor=124)
[ 106.640596][ T3819] Initialized host personality
[ 106.704604][ T3819] NET: Registered PF_VSOCK protocol family
[ 106.961049][ T3818] VFS: Warning: trinity-c7 using old stat() call. Recompile your binary.
[ 107.316143][ T3818] VFS: Warning: trinity-c7 using old stat() call. Recompile your binary.
[ 107.340298][ T3818] VFS: Warning: trinity-c7 using old stat() call. Recompile your binary.
[ 107.459492][ T3823] NET: Registered PF_IEEE802154 protocol family
[ 107.704743][ T3814] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[ 109.827821][ T3851] NET: Registered PF_KEY protocol family
[ 113.211528][ T3900] can: request_module (can-proto-3) failed.
[ 119.409606][ T3895] mmap: trinity-c3 (3895): VmData 15736832 exceed data ulimit 0. Update limits or use boot option ignore_rlimit_data.

Kboot worker: lkp-worker08
Elapsed time: 120

kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-meta-159.cgz
-m 16384
-smp 2


To reproduce:

# build kernel
cd linux
cp config-6.0.0-rc1-00030-g38a12ad69d86 .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) (13.10 kB)
config-6.0.0-rc1-00030-g38a12ad69d86 (185.28 kB)
job-script (4.57 kB)
dmesg.xz (14.67 kB)
Download all attachments