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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20220207132001.GA4838@xsang-OptiPlex-9020>
Date:   Mon, 7 Feb 2022 21:20:01 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Allison Henderson <allison.henderson@...cle.com>
Cc:     lkp@...ts.01.org, lkp@...el.com,
        LKML <linux-kernel@...r.kernel.org>
Subject: [xfs]  b519cd5b0b: INFO:task_blocked_for_more_than#seconds



Greeting,

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

commit: b519cd5b0b0155455c70512f3574660899d3a72f ("xfs: Add parent pointers to rename")
https://github.com/allisonhenderson/xfs_work.git delayed_attrs_v26_extended

in testcase: xfstests
version: xfstests-x86_64-972d710-1_20220127
with following parameters:

	disk: 4HDD
	fs: xfs
	test: generic-group-03
	ucode: 0x21

test-description: xfstests is a regression test suite for xfs and other files ystems.
test-url: git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git


on test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz with 16G memory

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>


[  988.684459][   T64] INFO: task rm:16266 blocked for more than 491 seconds.
[  988.684614][   T64]       Not tainted 5.16.0-rc5-00043-gb519cd5b0b01 #1
[  988.684726][   T64] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  988.684864][   T64] task:rm              state:D stack:    0 pid:16266 ppid: 15939 flags:0x00000000
[  988.685017][   T64] Call Trace:
[  988.685074][   T64]  <TASK>
[ 988.685127][ T64] __schedule (kernel/sched/core.c:4972 kernel/sched/core.c:6253) 
[ 988.685208][ T64] ? io_schedule_timeout (kernel/sched/core.c:6132) 
[ 988.685298][ T64] ? _raw_spin_lock_irq (arch/x86/include/asm/atomic.h:202 include/linux/atomic/atomic-instrumented.h:513 include/asm-generic/qspinlock.h:82 include/linux/spinlock.h:185 include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170) 
[ 988.685405][ T64] schedule (include/linux/instrumented.h:71 (discriminator 1) include/asm-generic/bitops/instrumented-non-atomic.h:134 (discriminator 1) include/linux/thread_info.h:118 (discriminator 1) include/linux/sched.h:2120 (discriminator 1) kernel/sched/core.c:6328 (discriminator 1)) 
[ 988.685487][ T64] rwsem_down_read_slowpath (kernel/locking/rwsem.c:1028) 
[ 988.685582][ T64] ? down_write (kernel/locking/rwsem.c:942) 
[ 988.685669][ T64] ? is_bpf_text_address (arch/x86/include/asm/preempt.h:85 include/linux/rcupdate.h:73 include/linux/rcupdate.h:720 kernel/bpf/core.c:717) 
[ 988.685757][ T64] ? kernel_text_address (kernel/extable.c:96 kernel/extable.c:93) 
[ 988.685845][ T64] ? unwind_get_return_address (arch/x86/kernel/unwind_orc.c:318 arch/x86/kernel/unwind_orc.c:313) 
[ 988.685940][ T64] ? create_prof_cpu_mask (kernel/stacktrace.c:83) 
[ 988.686028][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 988.686112][ T64] down_read (kernel/locking/rwsem.c:1468) 
[ 988.686185][ T64] ? rwsem_down_read_slowpath (kernel/locking/rwsem.c:1468) 
[ 988.686281][ T64] ? __kasan_kmalloc (mm/kasan/common.c:46 mm/kasan/common.c:434 mm/kasan/common.c:513 mm/kasan/common.c:522) 
[ 988.686399][ T64] xfs_ilock_data_map_shared (fs/xfs/xfs_inode.c:120) xfs
[ 988.686655][ T64] xfs_dir_lookup (fs/xfs/libxfs/xfs_dir2.c:381) xfs
[ 988.686854][ T64] ? xfs_dir_canenter (fs/xfs/libxfs/xfs_dir2.c:350) xfs
[ 988.687051][ T64] ? d_alloc (include/linux/list.h:69 include/linux/list.h:88 fs/dcache.c:1833) 
[ 988.687153][ T64] xfs_lookup (fs/xfs/xfs_inode.c:676) xfs
[ 988.687354][ T64] ? xfs_ip2xflags (fs/xfs/xfs_inode.c:666) xfs
[ 988.687573][ T64] xfs_vn_lookup (fs/xfs/xfs_iops.c:307) xfs
[ 988.687760][ T64] ? xfs_vn_link (fs/xfs/xfs_iops.c:296) xfs
[ 988.687946][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 988.688031][ T64] __lookup_slow (include/linux/dcache.h:371 fs/namei.c:1658) 
[ 988.688110][ T64] ? follow_up (fs/namei.c:1633) 
[ 988.688189][ T64] walk_component (include/linux/fs.h:798 fs/namei.c:1675 fs/namei.c:1970) 
[ 988.688269][ T64] ? __lookup_slow (fs/namei.c:1952) 
[ 988.688366][ T64] ? path_init (fs/namei.c:2361) 
[ 988.688465][ T64] ? lookup_positive_unlocked (fs/namei.c:2215) 
[ 988.688568][ T64] ? prep_new_page (mm/page_alloc.c:1265 mm/page_alloc.c:2408 mm/page_alloc.c:2418) 
[ 988.688652][ T64] path_lookupat+0x123/0x4c0 
[ 988.688740][ T64] filename_lookup (fs/namei.c:2479) 
[ 988.688822][ T64] ? may_linkat (fs/namei.c:2472) 
[ 988.688902][ T64] ? __mod_memcg_lruvec_state (mm/memcontrol.c:635 mm/memcontrol.c:708) 
[ 988.689000][ T64] ? __check_object_size (mm/usercopy.c:240 mm/usercopy.c:286 mm/usercopy.c:256) 
[ 988.689090][ T64] ? strncpy_from_user (arch/x86/include/asm/preempt.h:27 arch/x86/include/asm/uaccess.h:476 lib/strncpy_from_user.c:138) 
[ 988.689177][ T64] ? folio_add_lru (mm/swap.c:468) 
[ 988.689257][ T64] ? getname_flags (fs/namei.c:149 fs/namei.c:128) 
[ 988.689354][ T64] user_path_at_empty (fs/namei.c:2803) 
[ 988.689458][ T64] vfs_statx (fs/stat.c:222) 
[ 988.689545][ T64] ? vfs_getattr (fs/stat.c:204) 
[ 988.689623][ T64] ? userfaultfd_unmap_prep (fs/userfaultfd.c:825) 
[ 988.689717][ T64] __do_sys_newfstatat (fs/stat.c:413) 
[ 988.689803][ T64] ? __ia32_sys_newlstat (fs/stat.c:408) 
[ 988.689891][ T64] ? handle_mm_fault (mm/memory.c:4784) 
[ 988.689978][ T64] ? up_read (arch/x86/include/asm/atomic64_64.h:160 include/linux/atomic/atomic-long.h:71 include/linux/atomic/atomic-instrumented.h:1233 kernel/locking/rwsem.c:1302 kernel/locking/rwsem.c:1566) 
[ 988.690049][ T64] ? do_user_addr_fault (arch/x86/mm/fault.c:1423) 
[ 988.690138][ T64] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 988.690215][ T64] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[  988.690324][   T64] RIP: 0033:0x7f4f9e1d1e49
[  988.690427][   T64] RSP: 002b:00007ffe51fa6078 EFLAGS: 00000246 ORIG_RAX: 0000000000000106
[  988.690603][   T64] RAX: ffffffffffffffda RBX: 0000558372d27570 RCX: 00007f4f9e1d1e49
[  988.690759][   T64] RDX: 0000558372d275e8 RSI: 0000558372d27678 RDI: 00000000ffffff9c
[  988.690889][   T64] RBP: 0000558372d275e8 R08: 0000000000000100 R09: 0000000000000077
[  988.691017][   T64] R10: 0000000000000100 R11: 0000000000000246 R12: 0000558372d262b0
[  988.691150][   T64] R13: 00007ffe51fa63f8 R14: 0000000000000000 R15: 0000558372d27570
[  988.691279][   T64]  </TASK>
[ 1480.204436][   T64] INFO: task rm:16266 blocked for more than 983 seconds.
[ 1480.204579][   T64]       Not tainted 5.16.0-rc5-00043-gb519cd5b0b01 #1
[ 1480.204691][   T64] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1480.204829][   T64] task:rm              state:D stack:    0 pid:16266 ppid: 15939 flags:0x00000000
[ 1480.204980][   T64] Call Trace:
[ 1480.205038][   T64]  <TASK>
[ 1480.205090][ T64] __schedule (kernel/sched/core.c:4972 kernel/sched/core.c:6253) 
[ 1480.205171][ T64] ? io_schedule_timeout (kernel/sched/core.c:6132) 
[ 1480.205260][ T64] ? _raw_spin_lock_irq (arch/x86/include/asm/atomic.h:202 include/linux/atomic/atomic-instrumented.h:513 include/asm-generic/qspinlock.h:82 include/linux/spinlock.h:185 include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170) 
[ 1480.205361][ T64] schedule (include/linux/instrumented.h:71 (discriminator 1) include/asm-generic/bitops/instrumented-non-atomic.h:134 (discriminator 1) include/linux/thread_info.h:118 (discriminator 1) include/linux/sched.h:2120 (discriminator 1) kernel/sched/core.c:6328 (discriminator 1)) 
[ 1480.205445][ T64] rwsem_down_read_slowpath (kernel/locking/rwsem.c:1028) 
[ 1480.205541][ T64] ? down_write (kernel/locking/rwsem.c:942) 
[ 1480.205628][ T64] ? is_bpf_text_address (arch/x86/include/asm/preempt.h:85 include/linux/rcupdate.h:73 include/linux/rcupdate.h:720 kernel/bpf/core.c:717) 
[ 1480.205715][ T64] ? kernel_text_address (kernel/extable.c:96 kernel/extable.c:93) 
[ 1480.205806][ T64] ? unwind_get_return_address (arch/x86/kernel/unwind_orc.c:318 arch/x86/kernel/unwind_orc.c:313) 
[ 1480.205901][ T64] ? create_prof_cpu_mask (kernel/stacktrace.c:83) 
[ 1480.205989][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 1480.206083][ T64] down_read (kernel/locking/rwsem.c:1468) 
[ 1480.206174][ T64] ? rwsem_down_read_slowpath (kernel/locking/rwsem.c:1468) 
[ 1480.206278][ T64] ? __kasan_kmalloc (mm/kasan/common.c:46 mm/kasan/common.c:434 mm/kasan/common.c:513 mm/kasan/common.c:522) 
[ 1480.206395][ T64] xfs_ilock_data_map_shared (fs/xfs/xfs_inode.c:120) xfs
[ 1480.206643][ T64] xfs_dir_lookup (fs/xfs/libxfs/xfs_dir2.c:381) xfs
[ 1480.206833][ T64] ? xfs_dir_canenter (fs/xfs/libxfs/xfs_dir2.c:350) xfs
[ 1480.207015][ T64] ? d_alloc (include/linux/list.h:69 include/linux/list.h:88 fs/dcache.c:1833) 
[ 1480.207098][ T64] xfs_lookup (fs/xfs/xfs_inode.c:676) xfs
[ 1480.207290][ T64] ? xfs_ip2xflags (fs/xfs/xfs_inode.c:666) xfs
[ 1480.207499][ T64] xfs_vn_lookup (fs/xfs/xfs_iops.c:307) xfs
[ 1480.207696][ T64] ? xfs_vn_link (fs/xfs/xfs_iops.c:296) xfs
[ 1480.207883][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 1480.207967][ T64] __lookup_slow (include/linux/dcache.h:371 fs/namei.c:1658) 
[ 1480.208047][ T64] ? follow_up (fs/namei.c:1633) 
[ 1480.208124][ T64] walk_component (include/linux/fs.h:798 fs/namei.c:1675 fs/namei.c:1970) 
[ 1480.208204][ T64] ? __lookup_slow (fs/namei.c:1952) 
[ 1480.208284][ T64] ? path_init (fs/namei.c:2361) 
[ 1480.208379][ T64] ? lookup_positive_unlocked (fs/namei.c:2215) 
[ 1480.208474][ T64] ? prep_new_page (mm/page_alloc.c:1265 mm/page_alloc.c:2408 mm/page_alloc.c:2418) 
[ 1480.208567][ T64] path_lookupat+0x123/0x4c0 
[ 1480.208656][ T64] filename_lookup (fs/namei.c:2479) 
[ 1480.208738][ T64] ? may_linkat (fs/namei.c:2472) 
[ 1480.208817][ T64] ? __mod_memcg_lruvec_state (mm/memcontrol.c:635 mm/memcontrol.c:708) 
[ 1480.208912][ T64] ? __check_object_size (mm/usercopy.c:240 mm/usercopy.c:286 mm/usercopy.c:256) 
[ 1480.209003][ T64] ? strncpy_from_user (arch/x86/include/asm/preempt.h:27 arch/x86/include/asm/uaccess.h:476 lib/strncpy_from_user.c:138) 
[ 1480.209090][ T64] ? folio_add_lru (mm/swap.c:468) 
[ 1480.209169][ T64] ? getname_flags (fs/namei.c:149 fs/namei.c:128) 
[ 1480.209249][ T64] user_path_at_empty (fs/namei.c:2803) 
[ 1480.209350][ T64] vfs_statx (fs/stat.c:222) 
[ 1480.209425][ T64] ? vfs_getattr (fs/stat.c:204) 
[ 1480.209503][ T64] ? userfaultfd_unmap_prep (fs/userfaultfd.c:825) 
[ 1480.209606][ T64] __do_sys_newfstatat (fs/stat.c:413) 
[ 1480.209691][ T64] ? __ia32_sys_newlstat (fs/stat.c:408) 
[ 1480.209781][ T64] ? handle_mm_fault (mm/memory.c:4784) 
[ 1480.209866][ T64] ? up_read (arch/x86/include/asm/atomic64_64.h:160 include/linux/atomic/atomic-long.h:71 include/linux/atomic/atomic-instrumented.h:1233 kernel/locking/rwsem.c:1302 kernel/locking/rwsem.c:1566) 
[ 1480.209939][ T64] ? do_user_addr_fault (arch/x86/mm/fault.c:1423) 
[ 1480.210030][ T64] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 1480.210110][ T64] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[ 1480.210210][   T64] RIP: 0033:0x7f4f9e1d1e49
[ 1480.210287][   T64] RSP: 002b:00007ffe51fa6078 EFLAGS: 00000246 ORIG_RAX: 0000000000000106
[ 1480.210432][   T64] RAX: ffffffffffffffda RBX: 0000558372d27570 RCX: 00007f4f9e1d1e49
[ 1480.210572][   T64] RDX: 0000558372d275e8 RSI: 0000558372d27678 RDI: 00000000ffffff9c
[ 1480.210710][   T64] RBP: 0000558372d275e8 R08: 0000000000000100 R09: 0000000000000077
[ 1480.210839][   T64] R10: 0000000000000100 R11: 0000000000000246 R12: 0000558372d262b0
[ 1480.210970][   T64] R13: 00007ffe51fa63f8 R14: 0000000000000000 R15: 0000558372d27570
[ 1480.211099][   T64]  </TASK>
[ 1971.724386][   T64] INFO: task rm:16266 blocked for more than 1474 seconds.
[ 1971.724531][   T64]       Not tainted 5.16.0-rc5-00043-gb519cd5b0b01 #1
[ 1971.724643][   T64] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1971.724781][   T64] task:rm              state:D stack:    0 pid:16266 ppid: 15939 flags:0x00000000
[ 1971.724931][   T64] Call Trace:
[ 1971.724992][   T64]  <TASK>
[ 1971.725045][ T64] __schedule (kernel/sched/core.c:4972 kernel/sched/core.c:6253) 
[ 1971.725126][ T64] ? io_schedule_timeout (kernel/sched/core.c:6132) 
[ 1971.725215][ T64] ? _raw_spin_lock_irq (arch/x86/include/asm/atomic.h:202 include/linux/atomic/atomic-instrumented.h:513 include/asm-generic/qspinlock.h:82 include/linux/spinlock.h:185 include/linux/spinlock_api_smp.h:120 kernel/locking/spinlock.c:170) 
[ 1971.725315][ T64] schedule (include/linux/instrumented.h:71 (discriminator 1) include/asm-generic/bitops/instrumented-non-atomic.h:134 (discriminator 1) include/linux/thread_info.h:118 (discriminator 1) include/linux/sched.h:2120 (discriminator 1) kernel/sched/core.c:6328 (discriminator 1)) 
[ 1971.725397][ T64] rwsem_down_read_slowpath (kernel/locking/rwsem.c:1028) 
[ 1971.725492][ T64] ? down_write (kernel/locking/rwsem.c:942) 
[ 1971.725579][ T64] ? is_bpf_text_address (arch/x86/include/asm/preempt.h:85 include/linux/rcupdate.h:73 include/linux/rcupdate.h:720 kernel/bpf/core.c:717) 
[ 1971.725667][ T64] ? kernel_text_address (kernel/extable.c:96 kernel/extable.c:93) 
[ 1971.725757][ T64] ? unwind_get_return_address (arch/x86/kernel/unwind_orc.c:318 arch/x86/kernel/unwind_orc.c:313) 
[ 1971.725853][ T64] ? create_prof_cpu_mask (kernel/stacktrace.c:83) 
[ 1971.725950][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 1971.726053][ T64] down_read (kernel/locking/rwsem.c:1468) 
[ 1971.726143][ T64] ? rwsem_down_read_slowpath (kernel/locking/rwsem.c:1468) 
[ 1971.726248][ T64] ? __kasan_kmalloc (mm/kasan/common.c:46 mm/kasan/common.c:434 mm/kasan/common.c:513 mm/kasan/common.c:522) 
[ 1971.726363][ T64] xfs_ilock_data_map_shared (fs/xfs/xfs_inode.c:120) xfs
[ 1971.726595][ T64] xfs_dir_lookup (fs/xfs/libxfs/xfs_dir2.c:381) xfs
[ 1971.726777][ T64] ? xfs_dir_canenter (fs/xfs/libxfs/xfs_dir2.c:350) xfs
[ 1971.726965][ T64] ? d_alloc (include/linux/list.h:69 include/linux/list.h:88 fs/dcache.c:1833) 
[ 1971.727057][ T64] xfs_lookup (fs/xfs/xfs_inode.c:676) xfs
[ 1971.727249][ T64] ? xfs_ip2xflags (fs/xfs/xfs_inode.c:666) xfs
[ 1971.727456][ T64] xfs_vn_lookup (fs/xfs/xfs_iops.c:307) xfs
[ 1971.727654][ T64] ? xfs_vn_link (fs/xfs/xfs_iops.c:296) xfs
[ 1971.727841][ T64] ? arch_stack_walk (arch/x86/kernel/stacktrace.c:26) 
[ 1971.727925][ T64] __lookup_slow (include/linux/dcache.h:371 fs/namei.c:1658) 
[ 1971.728005][ T64] ? follow_up (fs/namei.c:1633) 
[ 1971.728082][ T64] walk_component (include/linux/fs.h:798 fs/namei.c:1675 fs/namei.c:1970) 
[ 1971.728162][ T64] ? __lookup_slow (fs/namei.c:1952) 
[ 1971.728244][ T64] ? path_init (fs/namei.c:2361) 
[ 1971.728327][ T64] ? lookup_positive_unlocked (fs/namei.c:2215) 
[ 1971.728431][ T64] ? prep_new_page (mm/page_alloc.c:1265 mm/page_alloc.c:2408 mm/page_alloc.c:2418) 
[ 1971.728525][ T64] path_lookupat+0x123/0x4c0 
[ 1971.728614][ T64] filename_lookup (fs/namei.c:2479) 
[ 1971.728695][ T64] ? may_linkat (fs/namei.c:2472) 
[ 1971.728773][ T64] ? __mod_memcg_lruvec_state (mm/memcontrol.c:635 mm/memcontrol.c:708) 
[ 1971.728868][ T64] ? __check_object_size (mm/usercopy.c:240 mm/usercopy.c:286 mm/usercopy.c:256) 
[ 1971.728959][ T64] ? strncpy_from_user (arch/x86/include/asm/preempt.h:27 arch/x86/include/asm/uaccess.h:476 lib/strncpy_from_user.c:138) 
[ 1971.729045][ T64] ? folio_add_lru (mm/swap.c:468) 
[ 1971.729125][ T64] ? getname_flags (fs/namei.c:149 fs/namei.c:128) 
[ 1971.729205][ T64] user_path_at_empty (fs/namei.c:2803) 
[ 1971.729303][ T64] vfs_statx (fs/stat.c:222) 
[ 1971.729397][ T64] ? vfs_getattr (fs/stat.c:204) 
[ 1971.729474][ T64] ? userfaultfd_unmap_prep (fs/userfaultfd.c:825) 
[ 1971.729577][ T64] __do_sys_newfstatat (fs/stat.c:413) 
[ 1971.729666][ T64] ? __ia32_sys_newlstat (fs/stat.c:408) 
[ 1971.729753][ T64] ? handle_mm_fault (mm/memory.c:4784) 
[ 1971.729838][ T64] ? up_read (arch/x86/include/asm/atomic64_64.h:160 include/linux/atomic/atomic-long.h:71 include/linux/atomic/atomic-instrumented.h:1233 kernel/locking/rwsem.c:1302 kernel/locking/rwsem.c:1566) 
[ 1971.729908][ T64] ? do_user_addr_fault (arch/x86/mm/fault.c:1423) 
[ 1971.729999][ T64] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 1971.730076][ T64] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[ 1971.730176][   T64] RIP: 0033:0x7f4f9e1d1e49
[ 1971.730253][   T64] RSP: 002b:00007ffe51fa6078 EFLAGS: 00000246 ORIG_RAX: 0000000000000106
[ 1971.730405][   T64] RAX: ffffffffffffffda RBX: 0000558372d27570 RCX: 00007f4f9e1d1e49
[ 1971.730535][   T64] RDX: 0000558372d275e8 RSI: 0000558372d27678 RDI: 00000000ffffff9c
[ 1971.730672][   T64] RBP: 0000558372d275e8 R08: 0000000000000100 R09: 0000000000000077
[ 1971.730801][   T64] R10: 0000000000000100 R11: 0000000000000246 R12: 0000558372d262b0
[ 1971.730929][   T64] R13: 00007ffe51fa63f8 R14: 0000000000000000 R15: 0000558372d27570
[ 1971.731058][   T64]  </TASK>
[ 2205.988682][  T413] generic/078	Tue Feb  1 16:44:27 UTC 2022 detected soft_timeout
[ 2205.988695][  T413]
[ 2206.034263][  T415] Terminated
[ 2206.034291][  T415]
[ 2206.035295][  T413] kill 1613 /usr/bin/time -v -o /tmp/lkp/xfstests.time /lkp/lkp/src/tests/xfstests
[ 2206.035306][  T413]
[ 2206.085635][  T413] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://internal-lkp-server:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/lkp-ivb-d01/xfstests-4HDD-xfs-generic-group-03-ucode=0x21-debian-10.4-x86_64-20200603.cgz-b519cd5b0b0155455c70512f3574660899d3a72f-20220201-11140-nwzcax-5.yaml&job_state=post_run -O /dev/null
[ 2206.085650][  T413]
[ 2206.751875][  T413] Tue Feb  1 16:44:28 UTC 2022 wait_job_finished --timeout 60
[ 2206.751886][  T413]
[ 2207.757037][  T413] kill 1553 vmstat --timestamp -n 10
[ 2207.757047][  T413]
[ 2207.767567][  T413] kill 1551 dmesg --follow --decode
[ 2207.767577][  T413]
[ 2207.782013][  T413] wait for background processes: 1560 1556 oom-killer meminfo
[ 2207.782023][  T413]
[ 2209.842870][   T95] ==================================================================
[ 2209.843027][ T95] BUG: KASAN: use-after-free in rwsem_down_write_slowpath (kernel/locking/rwsem.c:667 kernel/locking/rwsem.c:691 kernel/locking/rwsem.c:1068) 
[ 2209.843169][   T95] Read of size 4 at addr ffff888401180034 by task kworker/5:1/95
[ 2209.843318][   T95]
[ 2209.843382][   T95] CPU: 5 PID: 95 Comm: kworker/5:1 Not tainted 5.16.0-rc5-00043-gb519cd5b0b01 #1
[ 2209.843552][   T95] Hardware name:  /DZ77BH-55K, BIOS BHZ7710H.86A.0097.2012.1228.1346 12/28/2012
[ 2209.843718][   T95] Workqueue: xfs-inodegc/sda1 xfs_inodegc_worker [xfs]
[ 2209.843958][   T95] Call Trace:
[ 2209.844017][   T95]  <TASK>
[ 2209.844071][ T95] dump_stack_lvl (lib/dump_stack.c:107) 
[ 2209.844152][ T95] print_address_description+0x21/0x140 
[ 2209.844278][ T95] ? rwsem_down_write_slowpath (kernel/locking/rwsem.c:667 kernel/locking/rwsem.c:691 kernel/locking/rwsem.c:1068) 
[ 2209.844396][ T95] kasan_report.cold (mm/kasan/report.c:434 mm/kasan/report.c:450) 
[ 2209.844481][ T95] ? rwsem_down_write_slowpath (kernel/locking/rwsem.c:667 kernel/locking/rwsem.c:691 kernel/locking/rwsem.c:1068) 
[ 2209.844579][ T95] rwsem_down_write_slowpath (kernel/locking/rwsem.c:667 kernel/locking/rwsem.c:691 kernel/locking/rwsem.c:1068) 
[ 2209.844675][ T95] ? xlog_grant_head_wait (fs/xfs/xfs_log.c:294) xfs
[ 2209.844897][ T95] ? xlog_grant_add_space+0x85/0x100 xfs
[ 2209.845131][ T95] ? rwsem_spin_on_owner (kernel/locking/rwsem.c:1062) 
[ 2209.845222][ T95] ? xfs_log_reserve (fs/xfs/xfs_log.c:473) xfs
[ 2209.845434][ T95] ? xlog_ticket_alloc (fs/xfs/xfs_log.c:442) xfs
[ 2209.845643][ T95] ? fold_diff (arch/x86/include/asm/atomic64_64.h:46 include/linux/atomic/atomic-long.h:53 include/linux/atomic/atomic-instrumented.h:1212 mm/vmstat.c:796) 
[ 2209.845720][ T95] ? xfs_inactive_ifree (fs/xfs/xfs_inode.c:1714) xfs
[ 2209.845926][ T95] down_write (kernel/locking/rwsem.c:1525) 
[ 2209.846004][ T95] ? down_write_killable (kernel/locking/rwsem.c:1521) 
[ 2209.846096][ T95] ? xfs_trans_alloc (fs/xfs/xfs_trans.c:289) xfs
[ 2209.846299][ T95] ? xfs_inactive_ifree (fs/xfs/xfs_inode.c:1714) xfs
[ 2209.846501][ T95] xfs_ilock (fs/xfs/mrlock.h:38 fs/xfs/xfs_inode.c:201) xfs
[ 2209.846687][ T95] xfs_inactive_ifree (fs/xfs/xfs_inode.c:1714) xfs
[ 2209.846884][ T95] ? xfs_ifree (fs/xfs/xfs_inode.c:1659) xfs
[ 2209.847072][ T95] ? __raw_callee_save___native_queued_spin_unlock (??:?) 
[ 2209.847195][ T95] xfs_inactive (fs/xfs/xfs_inode.c:1892) xfs
[ 2209.847388][ T95] xfs_inodegc_worker (fs/xfs/xfs_icache.c:1827 fs/xfs/xfs_icache.c:1850) xfs
[ 2209.847583][ T95] process_one_work (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:212 include/trace/events/workqueue.h:108 kernel/workqueue.c:2303) 
[ 2209.847673][ T95] worker_thread (include/linux/list.h:284 kernel/workqueue.c:2446) 
[ 2209.847753][ T95] ? __kthread_parkme (arch/x86/include/asm/bitops.h:207 (discriminator 4) include/asm-generic/bitops/instrumented-non-atomic.h:135 (discriminator 4) kernel/kthread.c:249 (discriminator 4)) 
[ 2209.847841][ T95] ? schedule (arch/x86/include/asm/bitops.h:207 (discriminator 1) include/asm-generic/bitops/instrumented-non-atomic.h:135 (discriminator 1) include/linux/thread_info.h:118 (discriminator 1) include/linux/sched.h:2120 (discriminator 1) kernel/sched/core.c:6328 (discriminator 1)) 
[ 2209.847915][ T95] ? process_one_work (kernel/workqueue.c:2388) 
[ 2209.848005][ T95] ? process_one_work (kernel/workqueue.c:2388) 
[ 2209.848094][ T95] kthread (kernel/kthread.c:327) 
[ 2209.848168][ T95] ? set_kthread_struct (kernel/kthread.c:272) 
[ 2209.848266][ T95] ret_from_fork (arch/x86/entry/entry_64.S:301) 
[ 2209.848358][   T95]  </TASK>
[ 2209.848415][   T95]
[ 2209.848469][   T95] Allocated by task 1556:
[ 2209.848544][ T95] kasan_save_stack (mm/kasan/common.c:38) 
[ 2209.848626][ T95] __kasan_slab_alloc (mm/kasan/common.c:46 mm/kasan/common.c:434 mm/kasan/common.c:467) 
[ 2209.848710][ T95] kmem_cache_alloc_node (mm/slab.h:520 mm/slub.c:3234 mm/slub.c:3270) 
[ 2209.848799][ T95] dup_task_struct (kernel/fork.c:170 kernel/fork.c:882) 
[ 2209.848881][ T95] copy_process (kernel/fork.c:2023) 
[ 2209.848960][ T95] kernel_clone (kernel/fork.c:2582) 
[ 2209.849037][ T95] __do_sys_clone (kernel/fork.c:2688) 
[ 2209.849116][ T95] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 2209.849193][ T95] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[ 2209.849304][   T95]
[ 2209.849358][   T95] Freed by task 0:
[ 2209.849423][ T95] kasan_save_stack (mm/kasan/common.c:38) 
[ 2209.849504][ T95] kasan_set_track (mm/kasan/common.c:46) 
[ 2209.849583][ T95] kasan_set_free_info (mm/kasan/generic.c:372) 
[ 2209.849667][ T95] __kasan_slab_free (mm/kasan/common.c:368 mm/kasan/common.c:328 mm/kasan/common.c:374) 
[ 2209.849751][ T95] kmem_cache_free (mm/slub.c:1749 mm/slub.c:3513 mm/slub.c:3530) 
[ 2209.849832][ T95] rcu_do_batch (kernel/rcu/tree.c:2513) 
[ 2209.849911][ T95] rcu_core (kernel/rcu/tree.c:2741) 
[ 2209.849984][ T95] __do_softirq (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:212 include/trace/events/irq.h:142 kernel/softirq.c:559) 
[ 2209.850062][   T95]
[ 2209.850106][   T95] Last potentially related work creation:
[ 2209.850200][ T95] kasan_save_stack (mm/kasan/common.c:38) 
[ 2209.850292][ T95] __kasan_record_aux_stack (mm/kasan/generic.c:348) 
[ 2209.850392][ T95] call_rcu (kernel/rcu/tree.c:2986 kernel/rcu/tree.c:3065) 
[ 2209.850465][ T95] release_task (kernel/exit.c:229) 
[ 2209.850544][ T95] wait_task_zombie (kernel/exit.c:1114) 
[ 2209.850630][ T95] do_wait (kernel/exit.c:1406 kernel/exit.c:1521) 
[ 2209.850701][ T95] kernel_wait4 (kernel/exit.c:1685) 
[ 2209.850777][ T95] __do_sys_wait4 (kernel/exit.c:1712) 
[ 2209.850856][ T95] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 2209.850932][ T95] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[ 2209.851031][   T95]
[ 2209.851075][   T95] Second to last potentially related work creation:
[ 2209.851182][ T95] kasan_save_stack (mm/kasan/common.c:38) 
[ 2209.851277][ T95] __kasan_record_aux_stack (mm/kasan/generic.c:348) 
[ 2209.851378][ T95] call_rcu (kernel/rcu/tree.c:2986 kernel/rcu/tree.c:3065) 
[ 2209.851457][ T95] release_task (kernel/exit.c:229) 
[ 2209.851538][ T95] wait_task_zombie (kernel/exit.c:1114) 
[ 2209.851624][ T95] do_wait (kernel/exit.c:1406 kernel/exit.c:1521) 
[ 2209.851695][ T95] kernel_wait4 (kernel/exit.c:1685) 
[ 2209.851771][ T95] __do_sys_wait4 (kernel/exit.c:1712) 
[ 2209.851850][ T95] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 2209.851927][ T95] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113) 
[ 2209.852027][   T95]
[ 2209.852070][   T95] The buggy address belongs to the object at ffff888401180000
[ 2209.852070][   T95]  which belongs to the cache task_struct of size 10304
[ 2209.852314][   T95] The buggy address is located 52 bytes inside of
[ 2209.852314][   T95]  10304-byte region [ffff888401180000, ffff888401182840)
[ 2209.852535][   T95] The buggy address belongs to the page:
[ 2209.852628][   T95] page:00000000cdf169ba refcount:1 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x401180
[ 2209.852793][   T95] head:00000000cdf169ba order:3 compound_mapcount:0 compound_pincount:0
[ 2209.852928][   T95] memcg:ffff888410d05501
[ 2209.853001][   T95] flags: 0x17ffffc0010200(slab|head|node=0|zone=2|lastcpupid=0x1fffff)
[ 2209.853140][   T95] raw: 0017ffffc0010200 0000000000000000 dead000000000001 ffff88810005db80
[ 2209.853291][   T95] raw: 0000000000000000 0000000000030003 00000001ffffffff ffff888410d05501
[ 2209.853440][   T95] page dumped because: kasan: bad access detected
[ 2209.853545][   T95]
[ 2209.853588][   T95] Memory state around the buggy address:


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        sudo bin/lkp install job.yaml           # job file is attached in this email
        bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
        sudo bin/lkp run generated-yaml-file

        # if come across any failure that blocks the test,
        # please remove ~/.lkp and /lkp dir to run from a clean state.



---
0DAY/LKP+ Test Infrastructure                   Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org       Intel Corporation

Thanks,
Oliver Sang


View attachment "config-5.16.0-rc5-00043-gb519cd5b0b01" of type "text/plain" (177652 bytes)

View attachment "job-script" of type "text/plain" (5781 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (10376 bytes)

View attachment "xfstests" of type "text/plain" (41293 bytes)

View attachment "job.yaml" of type "text/plain" (4675 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ