| 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
| ||
|
Message-ID: <20180907030823.GD1110@shao2-debian>
Date: Fri, 7 Sep 2018 11:08:23 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Dennis Zhou <dennisszhou@...il.com>
Cc: Jens Axboe <axboe@...nel.dk>, Tejun Heo <tj@...nel.org>,
Johannes Weiner <hannes@...xchg.org>,
Josef Bacik <josef@...icpanda.com>, kernel-team@...com,
linux-block@...r.kernel.org, cgroups@...r.kernel.org,
linux-kernel@...r.kernel.org,
"Dennis Zhou (Facebook)" <dennisszhou@...il.com>, lkp@...org
Subject: [LKP] [blkcg] 6ef69a3a0b: WARNING:suspicious_RCU_usage
FYI, we noticed the following commit (built with gcc-7):
commit: 6ef69a3a0b4ac904f7c3b9cb78b5d51520dc84f4 ("[PATCH 13/15] blkcg: change blkg reference counting to use percpu_ref")
url: https://github.com/0day-ci/linux/commits/Dennis-Zhou/blkcg-ref-count-refactor-cleanup-blkcg-avg_lat/20180831-161742
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------------------------+------------+------------+
| | 22f657e287 | 6ef69a3a0b |
+------------------------------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 14 | 33 |
| WARNING:at_mm/slab_common.c:#kmalloc_slab | 14 | 33 |
| EIP:kmalloc_slab | 14 | 33 |
| Mem-Info | 14 | 33 |
| WARNING:at_arch/x86/mm/dump_pagetables.c:#note_page | 14 | 31 |
| EIP:note_page | 14 | 31 |
| WARNING:suspicious_RCU_usage | 0 | 33 |
| include/linux/rcupdate.h:#Illegal_context_switch_in_RCU_read-side_critical_section | 0 | 33 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0 | 33 |
+------------------------------------------------------------------------------------+------------+------------+
[ 5.313007] WARNING: suspicious RCU usage
[ 5.313705] 4.19.0-rc1-00175-g6ef69a3 #633 Tainted: G W
[ 5.314812] -----------------------------
[ 5.315231] include/linux/rcupdate.h:302 Illegal context switch in RCU read-side critical section!
[ 5.315231]
[ 5.315231] other info that might help us debug this:
[ 5.315231]
[ 5.315231]
[ 5.315231] rcu_scheduler_active = 2, debug_locks = 1
[ 5.315231] 4 locks held by swapper/1:
[ 5.315231] #0: (ptrval) (&dev->mutex){....}, at: __driver_attach+0x45/0xb0
[ 5.315231] #1: (ptrval) (ide_cfg_mtx){+.+.}, at: ide_port_setup_devices+0x1c/0x120
[ 5.315231] #2: (ptrval) (rcu_read_lock){....}, at: blkcg_init_queue+0x21/0x160
[ 5.315231] #3: (ptrval) (&(&q->__queue_lock)->rlock){....}, at: blkcg_init_queue+0x5e/0x160
[ 5.315231]
[ 5.315231] stack backtrace:
[ 5.315231] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.19.0-rc1-00175-g6ef69a3 #633
[ 5.315231] Call Trace:
[ 5.315231] ? dump_stack+0x16/0x26
[ 5.315231] ? lockdep_rcu_suspicious+0x91/0xa0
[ 5.315231] ? ___might_sleep+0x182/0x230
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __might_sleep+0x2d/0x80
[ 5.315231] ? __mutex_lock+0x21/0x4e0
[ 5.315231] ? kvm_sched_clock_read+0x14/0x30
[ 5.315231] ? sched_clock+0x9/0x10
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? mutex_lock_killable_nested+0x14/0x20
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? kfree+0xdd/0x140
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __alloc_percpu_gfp+0xb/0x10
[ 5.315231] ? percpu_ref_init+0x1e/0x90
[ 5.315231] ? blkg_create+0x18f/0x510
[ 5.315231] ? blkcg_init_queue+0x6c/0x160
[ 5.315231] ? blkcg_init_queue+0x21/0x160
[ 5.315231] ? blk_alloc_queue_node+0x2c5/0x370
[ 5.315231] ? ide_port_setup_devices+0x77/0x120
[ 5.315231] ? ide_host_register+0x567/0x5e0
[ 5.315231] ? ide_pci_init_two+0x56b/0x800
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? lockdep_hardirqs_on+0xec/0x1a0
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? trace_hardirqs_on+0x36/0xe0
[ 5.315231] ? __pm_runtime_resume+0x4e/0x80
[ 5.315231] ? ide_pci_init_one+0xd/0x10
[ 5.315231] ? piix_init_one+0x16/0x20
[ 5.315231] ? pci_device_probe+0xb5/0x140
[ 5.315231] ? really_probe+0x19b/0x290
[ 5.315231] ? driver_probe_device+0x49/0x140
[ 5.315231] ? __driver_attach+0xa9/0xb0
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_for_each_dev+0x4f/0x80
[ 5.315231] ? driver_attach+0x14/0x20
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_add_driver+0x157/0x1e0
[ 5.315231] ? pci_bus_num_vf+0x10/0x10
[ 5.315231] ? driver_register+0x51/0xe0
[ 5.315231] ? pdc202new_ide_init+0x16/0x16
[ 5.315231] ? __pci_register_driver+0x4b/0x50
[ 5.315231] ? piix_ide_init+0x8f/0x94
[ 5.315231] ? do_one_initcall+0xa1/0x1a7
[ 5.315231] ? rcu_read_lock_sched_held+0x4f/0x70
[ 5.315231] ? trace_initcall_level+0x57/0x80
[ 5.315231] ? kernel_init_freeable+0xdb/0x180
[ 5.315231] ? kernel_init_freeable+0x100/0x180
[ 5.315231] ? rest_init+0x90/0x90
[ 5.315231] ? kernel_init+0x8/0xf0
[ 5.315231] ? ret_from_fork+0x19/0x24
[ 5.315231] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:908
[ 5.315231] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper
[ 5.315231] 4 locks held by swapper/1:
[ 5.315231] #0: (ptrval) (&dev->mutex){....}, at: __driver_attach+0x45/0xb0
[ 5.315231] #1: (ptrval) (ide_cfg_mtx){+.+.}, at: ide_port_setup_devices+0x1c/0x120
[ 5.315231] #2: (ptrval) (rcu_read_lock){....}, at: blkcg_init_queue+0x21/0x160
[ 5.315231] #3: (ptrval) (&(&q->__queue_lock)->rlock){....}, at: blkcg_init_queue+0x5e/0x160
[ 5.315231] irq event stamp: 996210
[ 5.315231] hardirqs last enabled at (996209): [<47b49149>] kmem_cache_alloc_trace+0xa9/0x250
[ 5.315231] hardirqs last disabled at (996210): [<48cfea62>] _raw_spin_lock_irq+0x12/0x60
[ 5.315231] softirqs last enabled at (996106): [<48d01516>] __do_softirq+0x246/0x344
[ 5.315231] softirqs last disabled at (996097): [<47a0a74c>] do_softirq_own_stack+0x1c/0x30
[ 5.315231] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.19.0-rc1-00175-g6ef69a3 #633
[ 5.315231] Call Trace:
[ 5.315231] ? dump_stack+0x16/0x26
[ 5.315231] ? ___might_sleep+0x13b/0x230
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __might_sleep+0x2d/0x80
[ 5.315231] ? __mutex_lock+0x21/0x4e0
[ 5.315231] ? kvm_sched_clock_read+0x14/0x30
[ 5.315231] ? sched_clock+0x9/0x10
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? mutex_lock_killable_nested+0x14/0x20
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? kfree+0xdd/0x140
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __alloc_percpu_gfp+0xb/0x10
[ 5.315231] ? percpu_ref_init+0x1e/0x90
[ 5.315231] ? blkg_create+0x18f/0x510
[ 5.315231] ? blkcg_init_queue+0x6c/0x160
[ 5.315231] ? blkcg_init_queue+0x21/0x160
[ 5.315231] ? blk_alloc_queue_node+0x2c5/0x370
[ 5.315231] ? ide_port_setup_devices+0x77/0x120
[ 5.315231] ? ide_host_register+0x567/0x5e0
[ 5.315231] ? ide_pci_init_two+0x56b/0x800
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? lockdep_hardirqs_on+0xec/0x1a0
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? trace_hardirqs_on+0x36/0xe0
[ 5.315231] ? __pm_runtime_resume+0x4e/0x80
[ 5.315231] ? ide_pci_init_one+0xd/0x10
[ 5.315231] ? piix_init_one+0x16/0x20
[ 5.315231] ? pci_device_probe+0xb5/0x140
[ 5.315231] ? really_probe+0x19b/0x290
[ 5.315231] ? driver_probe_device+0x49/0x140
[ 5.315231] ? __driver_attach+0xa9/0xb0
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_for_each_dev+0x4f/0x80
[ 5.315231] ? driver_attach+0x14/0x20
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_add_driver+0x157/0x1e0
[ 5.315231] ? pci_bus_num_vf+0x10/0x10
[ 5.315231] ? driver_register+0x51/0xe0
[ 5.315231] ? pdc202new_ide_init+0x16/0x16
[ 5.315231] ? __pci_register_driver+0x4b/0x50
[ 5.315231] ? piix_ide_init+0x8f/0x94
[ 5.315231] ? do_one_initcall+0xa1/0x1a7
[ 5.315231] ? rcu_read_lock_sched_held+0x4f/0x70
[ 5.315231] ? trace_initcall_level+0x57/0x80
[ 5.315231] ? kernel_init_freeable+0xdb/0x180
[ 5.315231] ? kernel_init_freeable+0x100/0x180
[ 5.315231] ? rest_init+0x90/0x90
[ 5.315231] ? kernel_init+0x8/0xf0
[ 5.315231] ? ret_from_fork+0x19/0x24
[ 5.418590] ide_generic: please use "probe_mask=0x3f" module parameter for probing all legacy ISA IDE ports
[ 5.420208] Loading iSCSI transport class v2.0-870.
[ 5.424773] rdac: device handler registered
[ 5.425612] hp_sw: device handler registered
[ 5.426442] alua: device handler registered
[ 5.427168] st: Version 20160209, fixed bufsize 32768, s/g segs 256
[ 5.428294] osst :I: Tape driver with OnStream support version 0.99.4
[ 5.428294] osst :I: $Id: osst.c,v 1.73 2005/01/01 21:13:34 wriede Exp $
[ 5.431683] Rounding down aligned max_sectors from 4294967295 to 4294967288
[ 5.433091] db_root: cannot open: /etc/target
[ 5.434136] SSFDC read-only Flash Translation layer
[ 5.435107] L440GX flash mapping: failed to find PIIX4 ISA bridge, cannot continue
[ 5.436418] device id = 2440
[ 5.436921] device id = 2480
[ 5.437430] device id = 24c0
[ 5.437931] device id = 24d0
[ 5.438464] device id = 25a1
[ 5.438975] device id = 2670
[ 5.439673] slram: not enough parameters.
[ 5.557989] No valid DiskOnChip devices found
[ 5.575575] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.577267] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.578759] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.580241] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.581727] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.583206] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.584700] nand: device found, Manufacturer ID: 0x98, Chip ID: 0x39
[ 5.585730] nand: Toshiba NAND 128MiB 1,8V 8-bit
[ 5.586474] nand: 128 MiB, SLC, erase size: 16 KiB, page size: 512, OOB size: 16
[ 5.588284] flash size: 128 MiB
[ 5.588800] page size: 512 bytes
[ 5.589327] OOB area size: 16 bytes
[ 5.589887] sector size: 16 KiB
[ 5.591573] pages number: 262144
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-4.19.0-rc1-00175-g6ef69a3" of type "text/plain" (130290 bytes)
View attachment "job-script" of type "text/plain" (3940 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (32220 bytes)
Powered by blists - more mailing lists