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>] [<thread-prev] [thread-next>] [day] [month] [year] [list] 
Date:   Thu, 21 Feb 2019 21:32:59 +0800
From:   kernel test robot <lkp@...el.com>
To:     Kefeng Wang <wangkefeng.wang@...wei.com>
Cc:     netdev@...r.kernel.org, Willem de Bruijn <willemb@...gle.com>,
        "David S . Miller" <davem@...emloft.net>,
        Jay Vosburgh <j.vosburgh@...il.com>,
        Veaceslav Falico <vfalico@...il.com>,
        Eric Dumazet <edumazet@...gle.com>, weiyongjun1@...wei.com,
        Kefeng Wang <wangkefeng.wang@...wei.com>, lkp@...org
Subject: [bonding]  86838ad7bd:
 BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c

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

commit: 86838ad7bde0d7741b272670d94d535580173d95 ("[RFC PATCH] bonding: use mutex lock in bond_get_stats()")
url: https://github.com/0day-ci/linux/commits/Kefeng-Wang/bonding-use-mutex-lock-in-bond_get_stats/20190216-030058


in testcase: rcutorture
with following parameters:

	runtime: 300s
	test: cpuhotplug
	torture_type: srcu

test-description: rcutorture is rcutorture kernel module load/unload test.
test-url: https://www.kernel.org/doc/Documentation/RCU/torture.txt


on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 1G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+-----------------------------------------------------------------------------+------------+------------+
|                                                                             | f9bcc9f3ee | 86838ad7bd |
+-----------------------------------------------------------------------------+------------+------------+
| boot_successes                                                              | 50         | 24         |
| boot_failures                                                               | 10         | 41         |
| invoked_oom-killer:gfp_mask=0x                                              | 1          |            |
| Mem-Info                                                                    | 1          |            |
| Out_of_memory:Kill_process                                                  | 1          |            |
| BUG:kernel_in_stage                                                         | 6          | 8          |
| BUG:kernel_reboot-without-warning_in_early-boot_stage                       | 2          |            |
| BUG:kernel_hang_in_test_stage                                               | 1          | 1          |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0          | 32         |
+-----------------------------------------------------------------------------+------------+------------+



[   17.153431] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:908
[   17.157556] in_atomic(): 0, irqs_disabled(): 0, pid: 599, name: dropbearkey
[   17.159141] 2 locks held by dropbearkey/599:
[   17.159779]  #0: (____ptrval____) (&p->lock){+.+.}, at: seq_read+0x41/0x3f0
[   17.160802]  #1: (____ptrval____) (rcu_read_lock){....}, at: dev_seq_start+0x5/0x110
[   17.161928] Preemption disabled at:
[   17.161935] [<ffffffff818eafe0>] __mutex_lock+0x50/0x980
[   17.163150] CPU: 1 PID: 599 Comm: dropbearkey Not tainted 5.0.0-rc5-00320-g86838ad #1
[   17.164213] Call Trace:
[   17.164571]  dump_stack+0x67/0x90
[   17.165051]  ___might_sleep.cold.14+0xf0/0x106
[   17.165675]  ? bond_get_stats+0x3b/0x260
[   17.166232]  __mutex_lock+0x46/0x980
[   17.166743]  ? kvm_clock_read+0x14/0x30
[   17.167288]  ? validate_chain+0xb5/0xad0
[   17.167936]  ? number+0x2fc/0x340
[   17.168416]  ? bond_get_stats+0x3b/0x260
[   17.168966]  bond_get_stats+0x3b/0x260
[   17.169500]  ? seq_vprintf+0x30/0x50
[   17.170007]  ? seq_printf+0x43/0x50
[   17.170498]  ? validate_chain+0xb5/0xad0
[   17.171136]  ? dev_seq_printf_stats+0x9a/0xb0
[   17.171736]  dev_get_stats+0x55/0xb0
[   17.172221]  dev_seq_printf_stats+0x1f/0xb0
[   17.172817]  dev_seq_show+0x10/0x30
[   17.173289]  seq_read+0x2cd/0x3f0
[   17.173777]  proc_reg_read+0x36/0x60
[   17.174288]  __vfs_read+0x23/0x160
[   17.174779]  ? _copy_to_user+0x5e/0x70
[   17.175312]  ? entry_INT80_compat+0x7c/0x90
[   17.175903]  vfs_read+0xa6/0x140
[   17.176366]  ksys_read+0x42/0xa0
[   17.176834]  do_int80_syscall_32+0x4f/0x150
[   17.177418]  entry_INT80_compat+0x84/0x90
LKP: HOSTNAME vm-snb-openwrt-ia32-524, MAC , kernel 5.0.0-rc5-00320-g86838ad 1, serial console /dev/ttyS0
[   18.404764] Kernel tests: Boot OK!
[   18.404764] LKP: waiting for network...
[   19.256982] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[   19.271235] _warn_unseeded_randomness: 1329 callbacks suppressed
[   19.271244] random: get_random_u64 called from arch_pick_mmap_layout+0x65/0x170 with crng_init=0
[   19.273507] random: get_random_u64 called from arch_pick_mmap_layout+0x10e/0x170 with crng_init=0
[   19.274790] random: get_random_u64 called from load_elf_binary+0x87d/0x1120 with crng_init=0
[   20.407748] /lkp/lkp/src/bin/run-lkp
[   20.407748] RESULT_ROOT=/result/rcutorture/300s-cpuhotplug-srcu/vm-snb-openwrt-ia32/openwrt-i386-2016-03-16.cgz/x86_64-randconfig-s4-02200400/gcc-8/86838ad7bde0d7741b272670d94d535580173d95/3
[   20.407748] job=/lkp/jobs/scheduled/vm-snb-openwrt-ia32-524/rcutorture-300s-cpuhotplug-srcu-openwrt-i386-2016-03-16.cgz-20190220-89648-gjivxf-3.yaml
[   20.407748] run-job /lkp/jobs/scheduled/vm-snb-openwrt-ia32-524/rcutorture-300s-cpuhotplug-srcu-openwrt-i386-2016-03-16.cgz-20190220-89648-gjivxf-3.yaml
[   20.407748] /bin/busybox wget -q http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/vm-snb-openwrt-ia32-524/rcutorture-300s-cpuhotplug-srcu-openwrt-i386-2016-03-16.cgz-20190220-89648-gjivxf-3.yaml&job_state=running -O /dev/null
[   20.407748] target ucode: 
[   20.416008] wget: can't connect to remote host (192.168.1.1): Network is unreachable
[   20.416008] /lkp/lkp/src/monitors/heartbeat: line 9: vmstat: not found
[   20.416008] /lkp/lkp/src/monitors/heartbeat: exec: line 23: vmstat: not found
[   20.678602] _warn_unseeded_randomness: 431 callbacks suppressed
[   20.678610] random: get_random_u64 called from arch_pick_mmap_layout+0x65/0x170 with crng_init=0
[   20.681816] random: get_random_u64 called from arch_pick_mmap_layout+0x10e/0x170 with crng_init=0
[   20.683622] random: get_random_u64 called from load_elf_binary+0x87d/0x1120 with crng_init=0
[   21.418765] BusyBox v1.23.2 (2016-01-02 14:31:17 CET) multi-call binary.
[   21.418765] 
[   21.418765] Usage: time [-v] PROG ARGS
[   21.418765] 
[   21.418765] Run PROG, display resource usage when it exits
[   21.418765] 
[   21.418765] 	-v	Verbose
[   21.418765] 
[   21.418765] failed to load rcutorture module, try to enable CONFIG_RCU_TORTURE_TEST and build rcutorture.ko
[   21.418765] wget: can't connect to remote host (192.168.1.1): Network is unreachable
[   21.423344] 2019-02-20 06:29:25 modprobe rcutorture onoff_interval=3 onoff_holdoff=30 torture_type=srcu
[   21.423344] /bin/busybox wget -q http://inn:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_file=/lkp/jobs/scheduled/vm-snb-openwrt-ia32-524/rcutorture-300s-cpuhotplug-srcu-openwrt-i386-2016-03-16.cgz-20190220-89648-gjivxf-3.yaml&job_state=post_run -O /dev/null
[   21.818029] _warn_unseeded_randomness: 210 callbacks suppressed
[   21.818037] random: get_random_u64 called from arch_pick_mmap_layout+0x65/0x170 with crng_init=0
[   21.821714] random: get_random_u64 called from arch_pick_mmap_layout+0x10e/0x170 with crng_init=0
[   21.823918] random: get_random_u64 called from load_elf_binary+0x87d/0x1120 with crng_init=0
[   22.190264] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[   22.444763] kill 804 cat /proc/kmsg 
[   22.444763] wait for background processes: 812 810 oom-killer meminfo

Elapsed time: 20

qemu-img create -f qcow2 disk-vm-snb-openwrt-ia32-524-0 256G
qemu-img create -f qcow2 disk-vm-snb-openwrt-ia32-524-1 256G

kvm=(
	qemu-system-x86_64
	-enable-kvm
	-cpu SandyBridge
	-kernel $kernel
	-initrd initrd-vm-snb-openwrt-ia32-524
	-m 1024
	-smp 2
	-device e1000,netdev=net0
	-netdev user,id=net0
	-boot order=nc
	-no-reboot
	-watchdog i6300esb
	-watchdog-action debug
	-rtc base=localtime
	-drive file=disk-vm-snb-openwrt-ia32-524-0,media=disk,if=virtio
	-drive file=disk-vm-snb-openwrt-ia32-524-1,media=disk,if=virtio
	-serial stdio
	-display none
	-monitor null
)


To reproduce:

        git clone https://github.com/intel/lkp-tests.git
        cd lkp-tests
        bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



Thanks,
Rong Chen

View attachment "config-5.0.0-rc5-00320-g86838ad" of type "text/plain" (131690 bytes)

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

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ