Hi Bart,
CC linux-ide
On Fri, Jul 22, 2022 at 7:56 PM Bart Van Assche <bvanassche@xxxxxxx> wrote:
> On 7/22/22 01:53, Geert Uytterhoeven wrote:
> > During s2idle, the following trace data is generated:
> >
> > kworker/u16:9-325 [000] ...2. 230.478731: block_rq_issue: 8,0
> > N 0 () 0 + 0 [kworker/u16:9]
> > kworker/u16:9-325 [000] ...2. 230.478745:
> > scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=0 data_sgl=0
> > prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=0 scheduler_tag=0
> > cmnd=(SYNCHRONIZE_CACHE - raw=35 00 00 00 00 00 00 00 00 00)
> > <idle>-0 [007] d.h3. 230.478832:
> > scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=0 data_sgl=0
> > prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=0 scheduler_tag=0
> > cmnd=(SYNCHRONIZE_CACHE - raw=35 00 00 00 00 00 00 00 00 00)
> > result=(driver=DRIVER_OK host=DID_OK message=COMMAND_COMPLETE
> > status=SAM_STAT_GOOD)
> > <idle>-0 [000] ..s2. 230.478851: block_rq_complete:
> > 8,0 N () 18446744073709551615 + 0 [0]
> > kworker/u16:9-325 [000] ...2. 230.483134: block_rq_issue: 8,0
> > N 0 () 0 + 0 [kworker/u16:9]
> > kworker/u16:9-325 [000] ...2. 230.483136:
> > scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=0 data_sgl=0
> > prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=0 scheduler_tag=1
> > cmnd=(START_STOP - raw=1b 00 00 00 00 00)
> > <idle>-0 [007] d.h3. 230.624530:
> > scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=0 data_sgl=0
> > prot_sgl=0 prot_op=SCSI_PROT_NORMAL driver_tag=0 scheduler_tag=1
> > cmnd=(START_STOP - raw=1b 00 00 00 00 00) result=(driver=DRIVER_OK
> > host=DID_OK message=COMMAND_COMPLETE status=SAM_STAT_GOOD)
> > <idle>-0 [000] d.s4. 230.624634: scsi_eh_wakeup: host_no=0
> > <idle>-0 [000] ..s2. 230.624642: block_rq_complete:
> > 8,0 N () 18446744073709551615 + 0 [0]
> > kworker/u16:14-1027 [007] d..3. 231.393642: scsi_eh_wakeup: host_no=0
> >
> > When reading from hard drive after s2idle, no more trace data
> > is generated.
>
> I think the above commands come from the suspend sequence. '1b 00 00 00
> 00 00' stops a block device. The lowest bit in byte 4 needs to be set to
> start a block device.
>
> Something that is not yet clear is whether or not sd_submit_start()
> hangs during the resume process. How about verifying whether or not
> sd_submit_start() hangs by either issuing SysRq-t or by adding pr_info()
> statements in that function?
sd_submit_start() is called once during suspend, and once during
resume. It does not hang.
Reading from /dev/sda hangs after resume (not in sd_submit_start(),
which is never called for reading).
Two tasks are blocked in blk_mq_get_tag() calling io_schedule():
task:kworker/7:1 state:D stack: 0 pid: 122 ppid: 2 flags:0x00000008
Workqueue: events ata_scsi_dev_rescan
Call trace:
__switch_to+0xbc/0x124
__schedule+0x540/0x71c
schedule+0x58/0xa0
io_schedule+0x18/0x34
blk_mq_get_tag+0x138/0x244
__blk_mq_alloc_requests+0x130/0x2f0
blk_mq_alloc_request+0x74/0xa8
scsi_alloc_request+0x10/0x30
__scsi_execute+0x5c/0x18c
scsi_vpd_inquiry+0x7c/0xdc
scsi_get_vpd_size+0x34/0xa8
scsi_get_vpd_buf+0x28/0xf4
scsi_attach_vpd+0x44/0x170
scsi_rescan_device+0x30/0x98
ata_scsi_dev_rescan+0xc8/0xfc
process_one_work+0x2e0/0x474
worker_thread+0x1cc/0x270
kthread+0xd8/0xe8
ret_from_fork+0x10/0x20
task:hd state:D stack: 0 pid: 1163 ppid: 1076 flags:0x00000000
Call trace:
__switch_to+0xbc/0x124
__schedule+0x540/0x71c
schedule+0x58/0xa0
io_schedule+0x18/0x34
blk_mq_get_tag+0x138/0x244
__blk_mq_alloc_requests+0x130/0x2f0
blk_mq_submit_bio+0x44c/0x5b4
__submit_bio+0x24/0x5c
submit_bio_noacct_nocheck+0x8c/0x178
submit_bio_noacct+0x380/0x3b0
submit_bio+0x34/0x3c
mpage_bio_submit+0x28/0x38
mpage_readahead+0xa8/0x178
blkdev_readahead+0x14/0x1c
read_pages+0x4c/0x158
page_cache_ra_unbounded+0xd8/0x174
do_page_cache_ra+0x40/0x4c
page_cache_ra_order+0x14/0x1c
ondemand_readahead+0x124/0x2fc
page_cache_sync_ra+0x50/0x54
filemap_read+0x130/0x6e8
blkdev_read_iter+0xf0/0x164
new_sync_read+0x74/0xc0
vfs_read+0xbc/0xd8
ksys_read+0x6c/0xd4
__arm64_sys_read+0x14/0x1c
invoke_syscall+0x70/0xf4
el0_svc_common.constprop.0+0xbc/0xf0
do_el0_svc+0x18/0x20
el0_svc+0x30/0x84
el0t_64_sync_handler+0x90/0xf8
el0t_64_sync+0x14c/0x150
I hope this helps.
Thanks!
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@xxxxxxxxxxxxxx
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds
