[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20210215134523.GB15834@xsang-OptiPlex-9020>
Date: Mon, 15 Feb 2021 21:45:23 +0800
From: kernel test robot <oliver.sang@...el.com>
To: trondmy@...nel.org
Cc: 0day robot <lkp@...el.com>, LKML <linux-kernel@...r.kernel.org>,
lkp@...ts.01.org, Anna Schumaker <anna.schumaker@...app.com>,
linux-nfs@...r.kernel.org
Subject: [SUNRPC] 00003c0265:
BUG:sleeping_function_called_from_invalid_context_at_net/core/sock.c
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 00003c0265c6cb2b6e17e37f3a4b6bbab4e851b9 ("SUNRPC: Set TCP_CORK until the transmit queue is empty")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git trondmy-kernel-org/SUNRPC-Set-TCP_CORK-until-the-transmit-queue-is-empty/20210213-054525
in testcase: kernel-selftests
version: kernel-selftests-x86_64-b553cffa-1_20210122
with following parameters:
group: tc-testing
ucode: 0xe2
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 4 threads Intel(R) Core(TM) i5-6500 CPU @ 3.20GHz with 32G 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>
[ 55.839097] BUG: sleeping function called from invalid context at net/core/sock.c:3048
[ 55.847114] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 99, name: kworker/u9:0
[ 55.855394] 3 locks held by kworker/u9:0/99:
[ 55.859741] #0: ffff888101615938 ((wq_completion)xprtiod){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic64_64.h:34 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:856 kbuild/src/consumer/include/asm-generic/atomic-long.h:41 kbuild/src/consumer/kernel/workqueue.c:616 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246)
[ 55.869364] #1: ffffc90000807e58 ((work_completion)(&(&transport->connect_worker)->work)){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic64_64.h:34 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:856 kbuild/src/consumer/include/asm-generic/atomic-long.h:41 kbuild/src/consumer/kernel/workqueue.c:616 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246)
[ 55.881761] #2: ffff888816a58f08 (k-clock-AF_INET){++..}-{2:2}, at: xs_tcp_setup_socket (kbuild/src/consumer/net/sunrpc/xprtsock.c:1094 kbuild/src/consumer/net/sunrpc/xprtsock.c:2171 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 55.891016] Preemption disabled at:
[ 55.891032] 0x0
[ 55.898201] CPU: 2 PID: 99 Comm: kworker/u9:0 Not tainted 5.11.0-rc6-00001-g00003c0265c6 #1
[ 55.906623] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.8.1 12/05/2017
[ 55.914068] Workqueue: xprtiod xs_tcp_setup_socket
[ 55.918895] Call Trace:
[ 55.921372] dump_stack (kbuild/src/consumer/lib/dump_stack.c:122)
[ 55.924715] ___might_sleep.cold (kbuild/src/consumer/kernel/sched/core.c:7967)
[ 55.928930] lock_sock_nested (kbuild/src/consumer/include/linux/spinlock.h:359 kbuild/src/consumer/net/core/sock.c:3049)
[ 55.932807] tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 55.937025] xs_tcp_setup_socket (kbuild/src/consumer/arch/x86/include/asm/bitops.h:75 kbuild/src/consumer/include/asm-generic/bitops/instrumented-atomic.h:42 kbuild/src/consumer/include/linux/sunrpc/xprt.h:431 kbuild/src/consumer/net/sunrpc/xprtsock.c:2184 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 55.941343] process_one_work (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280)
[ 55.945402] worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422)
[ 55.949096] ? process_one_work (kbuild/src/consumer/kernel/workqueue.c:2364)
[ 55.953308] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 55.956578] ? kthread_park (kbuild/src/consumer/kernel/kthread.c:245)
[ 55.960274] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
[ 55.963927]
[ 55.965438] ======================================================
[ 55.971641] WARNING: possible circular locking dependency detected
[ 55.977848] 5.11.0-rc6-00001-g00003c0265c6 #1 Tainted: G W
[ 55.984661] ------------------------------------------------------
[ 55.990866] kworker/u9:0/99 is trying to acquire lock:
[ 55.996023] ffff888816a58c60 (sk_lock-AF_INET-RPC){+.+.}-{0:0}, at: tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 56.005023]
[ 56.005023] but task is already holding lock:
[ 56.010878] ffff888816a58f08 (k-clock-AF_INET){++..}-{2:2}, at: xs_tcp_setup_socket (kbuild/src/consumer/net/sunrpc/xprtsock.c:1094 kbuild/src/consumer/net/sunrpc/xprtsock.c:2171 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 56.019615]
[ 56.019615] which lock already depends on the new lock.
[ 56.019615]
[ 56.027824]
[ 56.027824] the existing dependency chain (in reverse order) is:
[ 56.035343]
[ 56.035343] -> #2 (k-clock-AF_INET){++..}-{2:2}:
[ 56.041475] __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4832)
[ 56.045852] lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:437 kbuild/src/consumer/kernel/locking/lockdep.c:5444 kbuild/src/consumer/kernel/locking/lockdep.c:5407)
[ 56.049964] _raw_read_lock_bh (kbuild/src/consumer/include/linux/rwlock_api_smp.h:177 kbuild/src/consumer/kernel/locking/spinlock.c:247)
[ 56.054426] sock_i_uid (kbuild/src/consumer/net/core/sock.c:2174)
[ 56.058283] inet_csk_update_fastreuse (kbuild/src/consumer/net/ipv4/inet_connection_sock.c:302)
[ 56.063542] inet_csk_get_port (kbuild/src/consumer/net/ipv4/inet_connection_sock.c:400)
[ 56.068178] __inet_bind (kbuild/src/consumer/net/ipv4/af_inet.c:528)
[ 56.072290] xs_bind (kbuild/src/consumer/net/sunrpc/xprtsock.c:1683)
[ 56.075969] xs_create_sock (kbuild/src/consumer/net/sunrpc/xprtsock.c:1792)
[ 56.080256] xs_tcp_setup_socket (kbuild/src/consumer/net/sunrpc/xprtsock.c:2235)
[ 56.085083] process_one_work (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280)
[ 56.089633] worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422)
[ 56.093832] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 56.097597] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
[ 56.101710]
[ 56.101710] -> #1 (&tcp_hashinfo.bhash[i].lock){+.-.}-{2:2}:
[ 56.108881] __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4832)
[ 56.113276] lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:437 kbuild/src/consumer/kernel/locking/lockdep.c:5444 kbuild/src/consumer/kernel/locking/lockdep.c:5407)
[ 56.117394] _raw_spin_lock_bh (kbuild/src/consumer/include/linux/spinlock_api_smp.h:136 kbuild/src/consumer/kernel/locking/spinlock.c:175)
[ 56.121879] inet_csk_get_port (kbuild/src/consumer/net/ipv4/inet_connection_sock.c:377)
[ 56.126521] __inet_bind (kbuild/src/consumer/net/ipv4/af_inet.c:528)
[ 56.130644] xs_bind (kbuild/src/consumer/net/sunrpc/xprtsock.c:1683)
[ 56.134330] xs_create_sock (kbuild/src/consumer/net/sunrpc/xprtsock.c:1792)
[ 56.138633] xs_tcp_setup_socket (kbuild/src/consumer/net/sunrpc/xprtsock.c:2235)
[ 56.143462] process_one_work (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280)
[ 56.148026] worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422)
[ 56.152225] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 56.155989] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
[ 56.160106]
[ 56.160106] -> #0 (sk_lock-AF_INET-RPC){+.+.}-{0:0}:
[ 56.166575] check_prev_add (kbuild/src/consumer/kernel/locking/lockdep.c:2869)
[ 56.170860] validate_chain (kbuild/src/consumer/kernel/locking/lockdep.c:2994 kbuild/src/consumer/kernel/locking/lockdep.c:3608)
[ 56.175335] __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4832)
[ 56.179711] lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:437 kbuild/src/consumer/kernel/locking/lockdep.c:5444 kbuild/src/consumer/kernel/locking/lockdep.c:5407)
[ 56.183823] lock_sock_nested (kbuild/src/consumer/include/linux/bottom_half.h:32 kbuild/src/consumer/net/core/sock.c:3058)
[ 56.188197] tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 56.192920] xs_tcp_setup_socket (kbuild/src/consumer/arch/x86/include/asm/bitops.h:75 kbuild/src/consumer/include/asm-generic/bitops/instrumented-atomic.h:42 kbuild/src/consumer/include/linux/sunrpc/xprt.h:431 kbuild/src/consumer/net/sunrpc/xprtsock.c:2184 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 56.197731] process_one_work (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280)
[ 56.202290] worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422)
[ 56.206490] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 56.210256] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
[ 56.214383]
[ 56.214383] other info that might help us debug this:
[ 56.214383]
[ 56.222428] Chain exists of:
[ 56.222428] sk_lock-AF_INET-RPC --> &tcp_hashinfo.bhash[i].lock --> k-clock-AF_INET
[ 56.222428]
[ 56.234656] Possible unsafe locking scenario:
[ 56.234656]
[ 56.240602] CPU0 CPU1
[ 56.245148] ---- ----
[ 56.249708] lock(k-clock-AF_INET);
[ 56.253296] lock(&tcp_hashinfo.bhash[i].lock);
[ 56.260492] lock(k-clock-AF_INET);
[ 56.266612] lock(sk_lock-AF_INET-RPC);
[ 56.270549]
[ 56.270549] *** DEADLOCK ***
[ 56.270549]
[ 56.276491] 3 locks held by kworker/u9:0/99:
[ 56.280779] #0: ffff888101615938 ((wq_completion)xprtiod){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic64_64.h:34 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:856 kbuild/src/consumer/include/asm-generic/atomic-long.h:41 kbuild/src/consumer/kernel/workqueue.c:616 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246)
[ 56.290305] #1: ffffc90000807e58 ((work_completion)(&(&transport->connect_worker)->work)){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic64_64.h:34 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:856 kbuild/src/consumer/include/asm-generic/atomic-long.h:41 kbuild/src/consumer/kernel/workqueue.c:616 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246)
[ 56.302632] #2: ffff888816a58f08 (k-clock-AF_INET){++..}-{2:2}, at: xs_tcp_setup_socket (kbuild/src/consumer/net/sunrpc/xprtsock.c:1094 kbuild/src/consumer/net/sunrpc/xprtsock.c:2171 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 56.311810]
[ 56.311810] stack backtrace:
[ 56.316183] CPU: 2 PID: 99 Comm: kworker/u9:0 Tainted: G W 5.11.0-rc6-00001-g00003c0265c6 #1
[ 56.325963] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.8.1 12/05/2017
[ 56.333388] Workqueue: xprtiod xs_tcp_setup_socket
[ 56.338202] Call Trace:
[ 56.340658] dump_stack (kbuild/src/consumer/lib/dump_stack.c:122)
[ 56.343988] check_noncircular (kbuild/src/consumer/kernel/locking/lockdep.c:2120)
[ 56.348016] ? save_trace (kbuild/src/consumer/kernel/locking/lockdep.c:554)
[ 56.351613] check_prev_add (kbuild/src/consumer/kernel/locking/lockdep.c:2869)
[ 56.355385] validate_chain (kbuild/src/consumer/kernel/locking/lockdep.c:2994 kbuild/src/consumer/kernel/locking/lockdep.c:3608)
[ 56.359344] __lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:4832)
[ 56.363217] lock_acquire (kbuild/src/consumer/kernel/locking/lockdep.c:437 kbuild/src/consumer/kernel/locking/lockdep.c:5444 kbuild/src/consumer/kernel/locking/lockdep.c:5407)
[ 56.366810] ? tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 56.371195] lock_sock_nested (kbuild/src/consumer/include/linux/bottom_half.h:32 kbuild/src/consumer/net/core/sock.c:3058)
[ 56.375055] ? tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 56.379434] tcp_sock_set_nodelay (kbuild/src/consumer/net/ipv4/tcp.c:3160 kbuild/src/consumer/net/ipv4/tcp.c:3171)
[ 56.383633] xs_tcp_setup_socket (kbuild/src/consumer/arch/x86/include/asm/bitops.h:75 kbuild/src/consumer/include/asm-generic/bitops/instrumented-atomic.h:42 kbuild/src/consumer/include/linux/sunrpc/xprt.h:431 kbuild/src/consumer/net/sunrpc/xprtsock.c:2184 kbuild/src/consumer/net/sunrpc/xprtsock.c:2250)
[ 56.387927] process_one_work (kbuild/src/consumer/arch/x86/include/asm/jump_label.h:25 kbuild/src/consumer/include/linux/jump_label.h:200 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280)
[ 56.391955] worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422)
[ 56.395633] ? process_one_work (kbuild/src/consumer/kernel/workqueue.c:2364)
[ 56.399835] kthread (kbuild/src/consumer/kernel/kthread.c:292)
[ 56.403080] ? kthread_park (kbuild/src/consumer/kernel/kthread.c:245)
[ 56.406758] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_64.S:302)
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml
bin/lkp run compatible-job.yaml
Thanks,
Oliver Sang
View attachment "config-5.11.0-rc6-00001-g00003c0265c6" of type "text/plain" (212603 bytes)
View attachment "job-script" of type "text/plain" (6460 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (51044 bytes)
View attachment "kernel-selftests" of type "text/plain" (113144 bytes)
View attachment "job.yaml" of type "text/plain" (5356 bytes)
View attachment "reproduce" of type "text/plain" (99 bytes)
Powered by blists - more mailing lists