linux-kernel - [lkp] [writeback] c284d3afba: INFO: suspicious RCU usage. ]

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: <20160801060847.GB13068@yexl-desktop>
Date:	Mon, 1 Aug 2016 14:08:47 +0800
From:	kernel test robot <xiaolong.ye@...el.com>
To:	Jens Axboe <axboe@...com>
Cc:	LKML <linux-kernel@...r.kernel.org>, Jens Axboe <axboe@...com>,
	Jens Axboe <axboe@...nel.dk>, lkp@...org
Subject: [lkp] [writeback]  c284d3afba: INFO: suspicious RCU usage. ]


FYI, we noticed the following commit:

https://git.kernel.org/pub/scm/linux/kernel/git/axboe/linux-block.git wb-buf-throttle
commit c284d3afba4e7f6a18122b416daceb994412ed6d ("writeback: throttle buffered writeback")

in testcase: boot

on test machine: 1 threads qemu-system-x86_64 -enable-kvm -cpu Westmere with 320M memory

caused below changes:


+---------------------------------+------------+------------+
|                                 | 0052d7a2a1 | c284d3afba |
+---------------------------------+------------+------------+
| boot_successes                  | 6          | 0          |
| boot_failures                   | 0          | 10         |
| INFO:suspicious_RCU_usage       | 0          | 10         |
| backtrace:disk_events_workfn+0x | 0          | 2          |
| backtrace:compat_SyS_mount+0x   | 0          | 2          |
| backtrace:compat_SyS_mount      | 0          | 2          |
| backtrace:SyS_open+0x           | 0          | 2          |
| backtrace:SyS_mount+0x          | 0          | 2          |
+---------------------------------+------------+------------+



Starting udev
[   55.583020] 
[   55.584026] ===============================
[   55.585419] [ INFO: suspicious RCU usage. ]
[   55.586823] 4.7.0-03460-gc284d3a #210 Not tainted
[   55.588307] -------------------------------
[   55.615491] include/linux/cgroup.h:434 suspicious rcu_dereference_check() usage!
[   55.618336] 
[   55.618336] other info that might help us debug this:
[   55.618336] 
[   55.647238] 
[   55.647238] rcu_scheduler_active = 1, debug_locks = 0
[   55.661574] 4 locks held by mount/2438:
[   55.663031]  #0:  (&bdev->bd_mutex){+.+.+.}, at: [<ffffffff812308ec>] __blkdev_get+0x96/0x3d0
[   55.666526]  #1:  (floppy_mutex){+.+.+.}, at: [<ffffffff81765ac6>] floppy_open+0x38/0x303
[   55.689474]  #2:  (open_lock){+.+.+.}, at: [<ffffffff81765ad4>] floppy_open+0x46/0x303
[   55.692618]  #3:  (floppy_lock){......}, at: [<ffffffff8155955c>] cfq_set_request+0x6d/0x33e
[   55.716947] 
[   55.716947] stack backtrace:
[   55.719105] CPU: 0 PID: 2438 Comm: mount Not tainted 4.7.0-03460-gc284d3a #210
[   55.742993] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[   55.746017]  0000000000000000 ffff88000b917748 ffffffff8155ee22 ffff88000b4da9c0
[   55.749043]  0000000000000001 ffff88000b917778 ffffffff810eb566 ffff88000b92e008
[   55.780401]  ffff88000b4da9c0 0000000000000003 ffff88000d1bc008 ffff88000b917838
[   55.783486] Call Trace:
[   55.784674]  [<ffffffff8155ee22>] dump_stack+0x86/0xc0
[   55.786349]  [<ffffffff810eb566>] lockdep_rcu_suspicious+0xf7/0x100
[   55.811201]  [<ffffffff815582a8>] check_blkcg_changed+0x202/0x402
[   55.813118]  [<ffffffff810ef045>] ? lock_acquire+0x180/0x21b
[   55.814932]  [<ffffffff8155955c>] ? cfq_set_request+0x6d/0x33e
[   55.816728]  [<ffffffff815595e1>] cfq_set_request+0xf2/0x33e
[   55.818299]  [<ffffffff81cd45af>] ? _raw_spin_unlock_irq+0x2c/0x3d
[   55.845138]  [<ffffffff810ed304>] ? trace_hardirqs_on_caller+0x17e/0x19a
[   55.847107]  [<ffffffff810ed32d>] ? trace_hardirqs_on+0xd/0xf
[   55.862515]  [<ffffffff81cd45af>] ? _raw_spin_unlock_irq+0x2c/0x3d
[   55.864248]  [<ffffffff8153ac1a>] ? ioc_create_icq+0x15b/0x172
[   55.866015]  [<ffffffff8152f63c>] elv_set_request+0x1f/0x24
[   55.867753]  [<ffffffff81533929>] get_request+0x5bb/0xaaf
[   55.904525]  [<ffffffff810e34a6>] ? wake_up_bit+0x2a/0x2a
[   55.906104]  [<ffffffff8153724f>] blk_queue_bio+0x1bd/0x4d0
[   55.907889]  [<ffffffff81535032>] generic_make_request+0xbd/0x15b
[   55.909686]  [<ffffffff815351d3>] submit_bio+0x103/0x10c
[   55.911418]  [<ffffffff81765737>] __floppy_read_block_0+0xd4/0x11f
[   55.928821]  [<ffffffff810ed170>] ? mark_held_locks+0x5e/0x74
[   55.930632]  [<ffffffff81cd456d>] ? _raw_spin_unlock_irqrestore+0x48/0x5e
[   55.932574]  [<ffffffff810ed304>] ? trace_hardirqs_on_caller+0x17e/0x19a
[   55.955101]  [<ffffffff8176561e>] ? floppy_resume+0x3f/0x3f
[   55.956862]  [<ffffffff81765921>] floppy_revalidate+0x19f/0x1b2
[   55.958712]  [<ffffffff8122fcba>] check_disk_change+0x52/0x5e
[   55.979912]  [<ffffffff81765d09>] floppy_open+0x27b/0x303
[   55.981584]  [<ffffffff8123095e>] __blkdev_get+0x108/0x3d0
[   55.983332]  [<ffffffff81230f00>] ? blkdev_get+0x2da/0x2fe
[   55.985102]  [<ffffffff81230ded>] blkdev_get+0x1c7/0x2fe
[   56.002462]  [<ffffffff81217fde>] ? mntput_no_expire+0xdd/0x350
[   56.004181]  [<ffffffff8121827e>] ? mntput+0x2d/0x2f
[   56.005839]  [<ffffffff81201a43>] ? path_put+0x1e/0x21
[   56.007550]  [<ffffffff81230f57>] blkdev_get_by_path+0x33/0x69
[   56.025545]  [<ffffffff811fba76>] mount_bdev+0x48/0x197
[   56.035638]  [<ffffffff812b2a20>] ? ext4_calculate_overhead+0x2bd/0x2bd
[   56.037650]  [<ffffffff812af08e>] ext4_mount+0x15/0x17
[   56.039248]  [<ffffffff811fc6a2>] mount_fs+0x14/0x8d
[   56.040773]  [<ffffffff81217465>] vfs_kern_mount+0x6b/0x133
[   56.042478]  [<ffffffff8121a673>] do_mount+0xa4d/0xb53
[   56.070772]  [<ffffffff811b823b>] ? strndup_user+0x3f/0x6b
[   56.072537]  [<ffffffff8124691e>] compat_SyS_mount+0x185/0x1ae
[   56.074325]  [<ffffffff81001e52>] do_int80_syscall_32+0x68/0x11a
[   56.076184]  [<ffffffff81cd70f8>] entry_INT80_compat+0x38/0x50
[   56.154399] blk_update_request: I/O error, dev fd0, sector 0
[   56.156125] floppy: error -5 while reading block 0


FYI, raw QEMU command line is:

	qemu-system-x86_64 -enable-kvm -cpu Westmere -kernel /pkg/linux/x86_64-nfsroot/gcc-6/c284d3afba4e7f6a18122b416daceb994412ed6d/vmlinuz-4.7.0-03460-gc284d3a -append 'ip=::::vm-kbuild-yocto-ia32-26::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-ia32-26/boot-1-yocto-minimal-i386.cgz-c284d3afba4e7f6a18122b416daceb994412ed6d-20160728-44712-tuwvmw-1.yaml ARCH=x86_64 kconfig=x86_64-nfsroot branch=block/wb-buf-throttle commit=c284d3afba4e7f6a18122b416daceb994412ed6d BOOT_IMAGE=/pkg/linux/x86_64-nfsroot/gcc-6/c284d3afba4e7f6a18122b416daceb994412ed6d/vmlinuz-4.7.0-03460-gc284d3a max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-ia32/yocto-minimal-i386.cgz/x86_64-nfsroot/gcc-6/c284d3afba4e7f6a18122b416daceb994412ed6d/0 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8'  -initrd /fs/sde1/initrd-vm-kbuild-yocto-ia32-26 -m 320 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -watchdog-action debug -rtc base=localtime -drive file=/fs/sde1/disk0-vm-kbuild-yocto-ia32-26,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-ia32-26 -serial file:/dev/shm/kboot/serial-vm-kbuild-yocto-ia32-26 -daemonize -display none -monitor null 





Thanks,
Xiaolong

View attachment "config-4.7.0-03460-gc284d3a" of type "text/plain" (111359 bytes)

Download attachment "dmesg.xz" of type "application/octet-stream" (15752 bytes)