On Mon, 2017-03-06 at 17:13 +0100, Jan Kara wrote: > On Mon 06-03-17 07:44:55, James Bottomley wrote: > > On Mon, 2017-03-06 at 16:14 +0100, Jan Kara wrote: > > > On Mon 06-03-17 06:35:21, James Bottomley wrote: > > > > On Mon, 2017-03-06 at 13:01 +0100, Jan Kara wrote: > > > > > On Mon 06-03-17 11:27:33, Jan Kara wrote: > > > > > > Hi, > > > > > > > > > > > > On Sun 05-03-17 10:21:11, Wu Fengguang wrote: > > > > > > > FYI next-20170303 is good while mainline is bad with this > > > > > > > error. > > > > > > > The attached reproduce-* may help reproduce the issue. > > > > > > > > > > > > Thanks for report! So from the stacktrace we are in the > > > > > > path > > > > > > testing removal of a device immediately after it has been > > > > > > probed > > > > > > and for some reason bdi_unregister() hangs - likely waiting > > > > > > for > > > > > > cgroup-writeback references to drop. Given how early this > > > > > > happens > > > > > > my guess is we fail to initialize something but for now I > > > > > > don't > > > > > > see > > > > > > how my patch could make a difference. I'm trying to > > > > > > reproduce > > > > > > this > > > > > > to be able to debug more... > > > > > > > > > > OK, so after some debugging I think this is yet another > > > > > problem > > > > > in > > > > > SCSI initialization / destruction code which my patch only > > > > > makes > > > > > visible (added relevant maintainers). > > > > > > > > > > I can reproduce the problem reliably with enabling: > > > > > > > > > > CONFIG_DEBUG_TEST_DRIVER_REMOVE=y > > > > > CONFIG_SCSI_DEBUG=m > > > > > CONFIG_BLK_CGROUP=y > > > > > CONFIG_MEMCG=y > > > > > (and thus CONFIG_CGROUP_WRITEBACK=y) > > > > > > > > > > then 'modprobe scsi_debug' is all it takes to reproduce hang. > > > > > Relevant kernel messages with some of my debugging added > > > > > (attached is > > > > > a patch that adds those debug messages): > > > > > > > > This looks to be precisely the same problem Dan Williams was > > > > debugging > > > > for us. > > > > > > > > > [ 58.721765] scsi host0: scsi_debug: version 1.86 > > > > > [20160430] > > > > > [ 58.721765] dev_size_mb=8, opts=0x0, submit_queues=1, > > > > > statistics=0 > > > > > [ 58.728946] CGWB init ffff88007fbb2000 > > > > > [ 58.730095] Created sdev ffff880078e1a000 > > > > > [ 58.731611] scsi 0:0:0:0: Direct-Access Linux > > > > > scsi_debug > > > > > 0186 PQ : 0 ANSI: 7 > > > > > [ 58.782246] sd 0:0:0:0: [sda] 16384 512-byte logical > > > > > blocks: > > > > > (8.39 > > > > > MB/8.00 MiB) > > > > > [ 58.789687] sd 0:0:0:0: [sda] Write Protect is off > > > > > [ 58.791140] sd 0:0:0:0: [sda] Mode Sense: 73 00 10 08 > > > > > [ 58.800879] sd 0:0:0:0: [sda] Write cache: enabled, read > > > > > cache: > > > > > enabled, supports DPO and FUA > > > > > [ 58.893738] sd 0:0:0:0: [sda] Attached SCSI disk > > > > > [ 58.896808] Unreg1 > > > > > [ 58.897960] Unreg2 > > > > > [ 58.898637] Unreg3 > > > > > [ 58.899100] CGWB ffff88007fbb2000 usage_cnt: 0 > > > > > [ 58.900004] Unreg4 > > > > > [ 58.904976] sd 0:0:0:0: [sda] Synchronizing SCSI cache > > > > > > > > OK, can you put a WARN_ON trace in sd_shutdown and tell us > > > > where > > > > this > > > > is coming from. For the device to be reused after this we have > > > > to > > > > be > > > > calling sd_shutdown() without going into SDEV_DEL. > > > > > > Sure. The call trace is: > > > > > > [ 41.919244] ------------[ cut here ]------------ > > > [ 41.919263] WARNING: CPU: 4 PID: 2335 at > > > drivers/scsi/sd.c:3332 > > > sd_shutdown+0x2f/0x100 > > > [ 41.919268] Modules linked in: scsi_debug(+) netconsole loop > > > btrfs > > > raid6_pq zlib_deflate lzo_compress xor > > > [ 41.919319] CPU: 4 PID: 2335 Comm: modprobe Not tainted 4.11.0 > > > -rc1 > > > -xen+ #49 > > > [ 41.919325] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 > > > [ 41.919331] Call Trace: > > > [ 41.919343] dump_stack+0x8e/0xf0 > > > [ 41.919354] __warn+0x116/0x120 > > > [ 41.919361] warn_slowpath_null+0x1d/0x20 > > > [ 41.919368] sd_shutdown+0x2f/0x100 > > > [ 41.919374] sd_remove+0x70/0xd0 > > > > > > *** Here is the unexpected step I guess... > > > > > > [ 41.919383] driver_probe_device+0xe0/0x4c0 > > > > Exactly. It's this, I think > > > > bool test_remove = IS_ENABLED(CONFIG_DEBUG_TEST_DRIVER_REMOVE) > > && > > !drv->suppress_bind_attrs; > > > > You have that config option set. > > Yes - or better said 0-day testing has it set. Maybe that is not a > sane default for 0-day tests? The option is explicitely marked as > "unstable"... Fengguang? > > > So the drivers base layer is calling ->remove after probe and > > triggering the destruction of the queue. > > > > What to do about this (apart from nuke such a stupid option) is > > somewhat more problematic. > > I guess this is between you and Greg :). Nice try, sport ... you qualify just behind Dan in the "not my problem" olympic hurdles event. I'm annoyed because there's no indication in the log that the driver add behaviour is radically altered, so I've been staring at the wrong code for weeks. However, the unbind/rebind should work, so the real issue is that your bdi changes (or perhaps something else in block) have induced a regression in the unbinding of upper layer drivers. If you're going to release the bdi in del_gendisk, you have to have some mechanism for re-acquiring it on re -probe (likely with the same name) otherwise rebind is broken for every block driver. The fact that the second rebind tried with a different name indicates that sd_devt_release wasn't called, so some vestige of the devt remains on the subsequent rebind. Here's the problem: the queue belongs to SCSI (the lower layer), so it's not going to change because it doesn't see the release. The gendisk and its allied stuff belongs to sd so it gets freed and re-created for the same queue. Something in block is very confused when this happens. James
