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

Powered by Openwall GNU/*/Linux Powered by OpenVZ