Re: [PATCH] block: Fix bug in runtime-resume handling

From: Martin Kepplinger <martin.kepplinger@puri.sm>
To: Alan Stern <stern@rowland.harvard.edu>
Cc: Bart Van Assche <bvanassche@acm.org>,
	Can Guo <cang@codeaurora.org>,
	linux-scsi@vger.kernel.org, linux-block@vger.kernel.org,
	kernel@puri.sm
Subject: Re: [PATCH] block: Fix bug in runtime-resume handling
Date: Sat, 29 Aug 2020 18:33:26 +0200	[thread overview]
Message-ID: <6d22ec22-a0c7-6a9d-439e-38ef87b0207c@puri.sm> (raw)
In-Reply-To: <20200829152635.GA498519@rowland.harvard.edu>

On 29.08.20 17:26, Alan Stern wrote:
> On Sat, Aug 29, 2020 at 09:24:30AM +0200, Martin Kepplinger wrote:
>> On 27.08.20 22:29, Alan Stern wrote:
>>> Instead, look at sd_resume().  That routine calls __scsi_execute() 
>>> indirectly through sd_start_stop_device(), and the only reason it does 
>>> this is because the sdkp->device->manage_start_stop flag is set.  You 
>>> ought to be able to clear this flag in sysfs, by writing to 
>>> /sys/block/sda/device/scsi_disk/*/manage_start_stop.  If you do this 
>>> before allowing the card reader to go into runtime suspend, does it then 
>>> resume okay?
>>
>> manage_start_stop in sysfs is 0 here.
> 
> Hmmm.  I'm wondering about something you wrote back in June 
> (https://marc.info/?l=linux-scsi&m=159345778431615&w=2):
> 
> 	blk_queue_enter() always - especially when sd is runtime 
> 	suspended and I try to mount as above - sets success to be true 
> 	for me, so never continues down to bkl_pm_request_resume(). All 
> 	I see is "PM: Removing info for No Bus:sda1".
> 
> blk_queue_enter() would always set success to be true because pm 
> (derived from the BLK_MQ_REQ_PREEMPT flag) is true.  But why was the 
> BLK_MQ_REQ_PREEMPT flag set?  In other words, where was 
> blk_queue_enter() called from?
> 
> Can you get a stack trace (i.e., call dump_stack()) at exactly this 
> point, that is, when pm is true and q->rpm_status is RPM_SUSPENDED?  Or 
> do you already know the answer?
> 
>

I reverted any scsi/block out-of-tree fixes for this.

when I try to mount, pm is TRUE (BLK_MQ_REQ_PREEMT set) and that's the
first stack trace I get in this condition, inside of blk_queue_enter():

There is more, but I don't know if that's interesting.

[   38.642202] CPU: 2 PID: 1522 Comm: mount Not tainted 5.8.0-1-librem5 #487
[   38.642207] Hardware name: Purism Librem 5r3 (DT)
[   38.642213] Call trace:
[   38.642233]  dump_backtrace+0x0/0x210
[   38.642242]  show_stack+0x20/0x30
[   38.642252]  dump_stack+0xc8/0x128
[   38.642262]  blk_queue_enter+0x1b8/0x2d8
[   38.642271]  blk_mq_alloc_request+0x54/0xb0
[   38.642277]  blk_get_request+0x34/0x78
[   38.642286]  __scsi_execute+0x60/0x1c8
[   38.642291]  scsi_test_unit_ready+0x88/0x118
[   38.642298]  sd_check_events+0x110/0x158
[   38.642306]  disk_check_events+0x68/0x188
[   38.642312]  disk_clear_events+0x84/0x198
[   38.642320]  check_disk_change+0x38/0x90
[   38.642325]  sd_open+0x60/0x148
[   38.642330]  __blkdev_get+0xcc/0x4c8
[   38.642335]  __blkdev_get+0x278/0x4c8
[   38.642339]  blkdev_get+0x128/0x1a8
[   38.642345]  blkdev_open+0x98/0xb0
[   38.642354]  do_dentry_open+0x130/0x3c8
[   38.642359]  vfs_open+0x34/0x40
[   38.642366]  path_openat+0xa30/0xe40
[   38.642372]  do_filp_open+0x84/0x100
[   38.642377]  do_sys_openat2+0x1f4/0x2b0
[   38.642382]  do_sys_open+0x60/0xa8
(...)

and of course it doesn't work and /dev/sda1 disappears, see the initial
discussion that led to your fix.