Date:   Wed, 4 May 2022 14:03:05 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Jens Axboe <axboe@...nel.dk>
Cc:     Ammar Faizi <ammarfaizi2@...weeb.org>, lkp@...ts.01.org,
        lkp@...el.com, ltp@...ts.linux.it,
        LKML <linux-kernel@...r.kernel.org>
Subject: [net]  5aa32dd9bd: INFO:task_blocked_for_more_than#seconds



Greeting,

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

commit: 5aa32dd9bdb57e4a26143216df5e90f5e5c3dd2c ("net: add support for fast socket release")
https://github.com/ammarfaizi2/linux-block axboe/linux-block/sock-nolock.2

in testcase: ltp
version: ltp-x86_64-14c1f76-1_20220430
with following parameters:

	test: cve
	ucode: 0x28

test-description: The LTP testsuite contains a collection of tools for testing the Linux kernel and related features.
test-url: http://linux-test-project.github.io/


on test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz 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>


[ 1483.168750][   T65] INFO: task setsockopt06:7672 blocked for more than 491 seconds.
[ 1483.171329][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.178802][   T65]       Not tainted 5.18.0-rc4-00071-g5aa32dd9bdb5 #1
[ 1483.183649][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.190232][   T65] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1483.190234][   T65] task:setsockopt06    state:D stack:    0 pid: 7672 ppid:     1 flags:0x00000004
[ 1483.195402][ T4173] pps pps0: removed
[ 1483.203890][   T65] Call Trace:
[ 1483.203892][   T65]  <TASK>
[ 1483.203906][ T65] __schedule (kernel/sched/core.c:5073 kernel/sched/core.c:6388) 
[ 1483.213541][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.216597][ T65] ? io_schedule_timeout (kernel/sched/core.c:6267) 
[ 1483.216614][ T65] 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:2154 (discriminator 1) kernel/sched/core.c:6462 (discriminator 1)) 
[ 1483.216619][ T65] __lock_sock (include/linux/spinlock.h:354 net/core/sock.c:2771) 
[ 1483.219775][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.222552][ T65] ? sock_omalloc (net/core/sock.c:2763) 
[ 1483.222568][ T65] ? prepare_to_swait_exclusive (kernel/sched/wait.c:414) 
[ 1483.226854][ T4173] pps pps0: removed
[ 1483.232055][ T65] ? _raw_spin_lock_bh (arch/x86/include/asm/atomic.h:202 include/linux/atomic/atomic-instrumented.h:543 include/asm-generic/qspinlock.h:82 include/linux/spinlock.h:185 include/linux/spinlock_api_smp.h:127 kernel/locking/spinlock.c:178) 
[ 1483.237811][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.241124][ T65] ? _raw_spin_lock (kernel/locking/spinlock.c:177) 
[ 1483.241139][ T65] lock_sock_nested (net/core/sock.c:3317) 
[ 1483.245333][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.250450][ T65] packet_setsockopt (net/packet/af_packet.c:3783) 
[ 1483.255011][ T4173] pps pps0: removed
[ 1483.260730][ T65] ? fanout_add (net/packet/af_packet.c:3746) 
[ 1483.264979][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.269274][ T65] ? send_call_function_single_ipi (kernel/sched/core.c:925 kernel/sched/core.c:3764) 
[ 1483.274520][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.279204][ T65] ? generic_exec_single (kernel/smp.c:496 kernel/smp.c:529) 
[ 1483.279222][ T65] ? __fget_files (arch/x86/include/asm/atomic64_64.h:22 include/linux/atomic/atomic-arch-fallback.h:2293 include/linux/atomic/atomic-arch-fallback.h:2318 include/linux/atomic/atomic-long.h:491 include/linux/atomic/atomic-instrumented.h:1846 fs/file.c:903 fs/file.c:934) 
[ 1483.283857][ T4173] pps pps0: removed
[ 1483.288970][ T65] ? __fget_light (fs/file.c:1039 fs/file.c:1027) 
[ 1483.294359][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.297519][ T65] ? __hrtimer_run_queues (kernel/time/hrtimer.c:1702 kernel/time/hrtimer.c:1749) 
[ 1483.302070][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.307268][ T65] ? sockfd_lookup_light (net/socket.c:551) 
[ 1483.307286][ T65] __sys_setsockopt (net/socket.c:2214) 
[ 1483.313222][ T4173] pps pps0: removed
[ 1483.318325][ T65] ? __ia32_sys_recv (net/socket.c:2177) 
[ 1483.323890][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.327913][ T65] ? sched_clock_cpu (kernel/sched/clock.c:369) 
[ 1483.331595][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.336015][ T65] ? __do_softirq (arch/x86/include/asm/preempt.h:85 kernel/softirq.c:346 kernel/softirq.c:401 kernel/softirq.c:587) 
[ 1483.341276][ T4173] pps pps0: removed
[ 1483.346467][ T65] __x64_sys_setsockopt (net/socket.c:2220) 
[ 1483.346484][ T65] ? __irq_exit_rcu (kernel/softirq.c:620 kernel/softirq.c:639) 
[ 1483.352065][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.356661][ T65] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80) 
[ 1483.361382][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.365027][ T65] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:115) 
[ 1483.365044][   T65] RIP: 0033:0x7f34ce93149a
[ 1483.369857][ T4173] pps pps0: removed
[ 1483.375045][   T65] RSP: 002b:00007f34ce832e98 EFLAGS: 00000206 ORIG_RAX: 0000000000000036
[ 1483.375062][   T65] RAX: ffffffffffffffda RBX: 00007f34ce832eb0 RCX: 00007f34ce93149a
[ 1483.380287][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.384893][   T65] RDX: 0000000000000005 RSI: 0000000000000107 RDI: 0000000000000004
[ 1483.384896][   T65] RBP: 0000000000000000 R08: 000000000000001c R09: 0000000000000004
[ 1483.384909][   T65] R10: 00007f34ce832eb0 R11: 0000000000000206 R12: 0000000000000000
[ 1483.384912][   T65] R13: 00007fff549f2c2f R14: 00007f34ce833700 R15: 0000000000000124
[ 1483.389457][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.393098][   T65]  </TASK>
[ 1483.491547][ T4173] pps pps0: removed
[ 1483.495703][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.500938][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.506112][ T4173] pps pps0: removed
[ 1483.510200][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.515510][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.520690][ T4173] pps pps0: removed
[ 1483.524760][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.529987][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.535163][ T4173] pps pps0: removed
[ 1483.539246][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.544542][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.549717][ T4173] pps pps0: removed
[ 1483.553852][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.559083][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.564245][ T4173] pps pps0: removed
[ 1483.568393][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.573685][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.578830][ T4173] pps pps0: removed
[ 1483.582979][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.588214][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.593364][ T4173] pps pps0: removed
[ 1483.597487][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.602762][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.607912][ T4173] pps pps0: removed
[ 1483.612084][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.617321][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.622486][ T4173] pps pps0: removed
[ 1483.626708][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.631953][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.637117][ T4173] pps pps0: removed
[ 1483.641248][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.646528][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.651692][ T4173] pps pps0: removed
[ 1483.655852][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.661085][ T4173] pps pps0: source "/dev/pts4" added
[ 1483.666245][ T4173] pps pps0: removed
[ 1483.670388][ T4173] pps pps0: new PPS source pty_slave4
[ 1483.675688][ T4173] pps pps0: source "/dev/pts4" added


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.



-- 
0-DAY CI Kernel Test Service
https://01.org/lkp



View attachment "config-5.18.0-rc4-00071-g5aa32dd9bdb5" of type "text/plain" (166090 bytes)

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

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

View attachment "ltp" of type "text/plain" (745029 bytes)

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

View attachment "reproduce" of type "text/plain" (62 bytes)

Powered by blists - more mailing lists