Re: [RFC PATCH] usb: storage: uas: limit consecutive device resets in error handling

[Sergey Senozhatsky]

On (26/07/01 07:38), Greg KH wrote:
> > +static int uas_reset_limit = 3;

This obviously wanted to be 0 by default (just a side note).

> > +module_param_named(reset_limit, uas_reset_limit, int, 0644);
> > +MODULE_PARM_DESC(reset_limit, "Maximum number of consecutive device resets during error handling before failing");
> 
> This is not the 1990's, we do not add module parameters for issues that
> should be properly solved either automatically, or on a per-device
> basis.
> 
> There's no way that ChromeOs wants to attempt to track this module
> parameter as a bootline config option, right?

Can you please elaborate on "properly solved either automatically,
or on a per-device basis".  I don't know how to break that endless
reset loop otherwise.  I'm open to any suggestions, the patch is RFC
for a reason.

That reset loop essentially panics the system (we have hung-task watchdog
and hung-task panic enabled).  The kernel does uas_eh_device_reset_handler()
every 30 seconds (which succeeds), while the block layer doesn't make progress
and keeps the tasks blocked, which eventually triggers the watchdog:

[..]
<6>[ 917.070222] sd 0:0:0:0: [sda] tag#3 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD IN
<6>[ 917.070318] sd 0:0:0:0: [sda] tag#3 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
<6>[ 917.079434] scsi host0: uas_eh_device_reset_handler start
<6>[ 917.079994] sd 0:0:0:0: [sda] tag#1 uas_zap_pending 0 uas-tag 1 inflight: CMD
<6>[ 917.080046] sd 0:0:0:0: [sda] tag#1 CDB: Write(10) 2a 00 00 d3 98 08 00 04 00 00
<6>[ 917.080072] sd 0:0:0:0: [sda] tag#2 uas_zap_pending 0 uas-tag 2 inflight: CMD
<6>[ 917.080118] sd 0:0:0:0: [sda] tag#2 CDB: Write(10) 2a 00 00 d3 9c 08 00 04 00 00
<6>[ 917.145714] usb 2-1.3: reset SuperSpeed Plus Gen 2x1 USB device number 4 using xhci_hcd
<6>[ 917.164988] scsi host0: uas_eh_device_reset_handler success
<6>[ 917.165155] sd 0:0:0:0: [sda] tag#3 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK cmd_age=30s
<6>[ 917.165210] sd 0:0:0:0: [sda] tag#3 CDB: Read(10) 28 00 00 00 00 00 00 00 20 00
<3>[ 917.165239] I/O error, dev sda, sector 0 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 3
<4>[ 934.971114] rq: tag=0 hctx=0 op=WRITE sector=13867016 len=524288 age=78231 ms pid=11900 comm=image_burner state=D
<4>[ 934.971169] rq: tag=1 hctx=0 op=WRITE sector=13868040 len=524288 age=78230 ms pid=11900 comm=image_burner state=D
<4>[ 934.971217] blk: queue stall on sda: 3 inflight, 2 stalled (threshold 60000 ms)
<6>[ 947.276222] sd 0:0:0:0: [sda] tag#3 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD IN
<6>[ 947.276282] sd 0:0:0:0: [sda] tag#3 CDB: Read(10) 28 00 00 00 00 00 00 00 08 00
<6>[ 947.280489] scsi host0: uas_eh_device_reset_handler start
<6>[ 947.281255] sd 0:0:0:0: [sda] tag#0 uas_zap_pending 0 uas-tag 1 inflight: CMD
<6>[ 947.281309] sd 0:0:0:0: [sda] tag#0 CDB: Write(10) 2a 00 00 d3 98 08 00 04 00 00
<6>[ 947.281391] sd 0:0:0:0: [sda] tag#1 uas_zap_pending 0 uas-tag 2 inflight: CMD
<6>[ 947.281468] sd 0:0:0:0: [sda] tag#1 CDB: Write(10) 2a 00 00 d3 9c 08 00 04 00 00
<6>[ 947.346666] usb 2-1.3: reset SuperSpeed Plus Gen 2x1 USB device number 4 using xhci_hcd
<6>[ 947.365031] scsi host0: uas_eh_device_reset_handler success
<6>[ 977.479406] scsi host0: uas_eh_device_reset_handler start
<6>[ 977.479963] sd 0:0:0:0: [sda] tag#2 uas_zap_pending 0 uas-tag 1 inflight: CMD
<6>[ 977.480015] sd 0:0:0:0: [sda] tag#2 CDB: Write(10) 2a 00 00 d3 98 08 00 04 00 00
<6>[ 977.480042] sd 0:0:0:0: [sda] tag#3 uas_zap_pending 0 uas-tag 2 inflight: CMD
<6>[ 977.480089] sd 0:0:0:0: [sda] tag#3 CDB: Write(10) 2a 00 00 d3 9c 08 00 04 00 00
<6>[ 977.480137] sd 0:0:0:0: [sda] tag#4 uas_zap_pending 0 uas-tag 3 inflight: CMD
<6>[ 977.480166] sd 0:0:0:0: [sda] tag#4 CDB: Read(10) 28 00 00 00 00 00 00 00 08 00
<6>[ 977.545653] usb 2-1.3: reset SuperSpeed Plus Gen 2x1 USB device number 4 using xhci_hcd
<6>[ 977.565338] scsi host0: uas_eh_device_reset_handler success
<3>[ 984.123394] INFO: task image_burner:11900 blocked for more than 122 seconds.
<3>[ 984.123501] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 984.123517] task:image_burner state:D stack:0 pid:11900 ppid:11893 flags:0x00004002
<6>[ 984.123577] Call Trace:
<6>[ 984.123603] <TASK>
<6>[ 984.123659] __schedule+0x5e8/0x14c0
<6>[ 984.123688] ? free_unref_page_list+0x25d/0x290
<6>[ 984.123715] ? lru_gen_update_size+0x1e3/0x220
<6>[ 984.123763] schedule+0x5e/0xa0
<6>[ 984.123788] io_schedule+0x47/0x70
<6>[ 984.123814] folio_wait_bit_common+0x18a/0x270
<6>[ 984.123863] ? __pfx_wake_page_function+0x10/0x10
<6>[ 984.123889] folio_wait_writeback+0x35/0x90
<6>[ 984.123937] __filemap_fdatawait_range+0x162/0x190
<6>[ 984.123965] file_write_and_wait_range+0xa3/0x120
<6>[ 984.124013] blkdev_fsync+0x39/0x60
<6>[ 984.124040] __x64_sys_fdatasync+0x4c/0x90
<6>[ 984.124067] do_syscall_64+0x6b/0xa0