| From: Steffen Maier <maier@linux.ibm.com> |
| Date: Thu, 17 May 2018 19:14:44 +0200 |
| Subject: scsi: zfcp: fix missing SCSI trace for retry of abort / scsi_eh TMF |
| |
| commit 81979ae63e872ef650a7197f6ce6590059d37172 upstream. |
| |
| We already have a SCSI trace for the end of abort and scsi_eh TMF. Due to |
| zfcp_erp_wait() and fc_block_scsi_eh() time can pass between the start of |
| our eh callback and an actual send/recv of an abort / TMF request. In order |
| to see the temporal sequence including any abort / TMF send retries, add a |
| trace before the above two blocking functions. This supports problem |
| determination with scsi_eh and parallel zfcp ERP. |
| |
| No need to explicitly trace the beginning of our eh callback, since we |
| typically can send an abort / TMF and see its HBA response (in the worst |
| case, it's a pseudo response on dismiss all of adapter recovery, e.g. due to |
| an FSF request timeout [fsrth_1] of the abort / TMF). If we cannot send, we |
| now get a trace record for the first "abrt_wt" or "[lt]r_wait" which denotes |
| almost the beginning of the callback. |
| |
| No need to explicitly trace the wakeup after the above two blocking |
| functions because the next retry loop causes another trace in any case and |
| that is sufficient. |
| |
| Example trace records formatted with zfcpdbf from s390-tools: |
| |
| Timestamp : ... |
| Area : SCSI |
| Subarea : 00 |
| Level : 1 |
| Exception : - |
| CPU ID : .. |
| Caller : 0x... |
| Record ID : 1 |
| Tag : abrt_wt abort, before zfcp_erp_wait() |
| Request ID : 0x0000000000000000 none (invalid) |
| SCSI ID : 0x<scsi_id> |
| SCSI LUN : 0x<scsi_lun> |
| SCSI LUN high : 0x<scsi_lun_high> |
| SCSI result : 0x<scsi_result_of_cmd_to_be_aborted> |
| SCSI retries : 0x<retries_of_cmd_to_be_aborted> |
| SCSI allowed : 0x<allowed_retries_of_cmd_to_be_aborted> |
| SCSI scribble : 0x<req_id_of_cmd_to_be_aborted> |
| SCSI opcode : <CDB_of_cmd_to_be_aborted> |
| FCP rsp inf cod: 0x.. none (invalid) |
| FCP rsp IU : ... none (invalid) |
| |
| Timestamp : ... |
| Area : SCSI |
| Subarea : 00 |
| Level : 1 |
| Exception : - |
| CPU ID : .. |
| Caller : 0x... |
| Record ID : 1 |
| Tag : lr_wait LUN reset, before zfcp_erp_wait() |
| Request ID : 0x0000000000000000 none (invalid) |
| SCSI ID : 0x<scsi_id> |
| SCSI LUN : 0x<scsi_lun> |
| SCSI LUN high : 0x<scsi_lun_high> |
| SCSI result : 0x... unrelated |
| SCSI retries : 0x.. unrelated |
| SCSI allowed : 0x.. unrelated |
| SCSI scribble : 0x... unrelated |
| SCSI opcode : ... unrelated |
| FCP rsp inf cod: 0x.. none (invalid) |
| FCP rsp IU : ... none (invalid) |
| |
| Signed-off-by: Steffen Maier <maier@linux.ibm.com> |
| Fixes: 63caf367e1c9 ("[SCSI] zfcp: Improve reliability of SCSI eh handlers in zfcp") |
| Fixes: af4de36d911a ("[SCSI] zfcp: Block scsi_eh thread for rport state BLOCKED") |
| Reviewed-by: Benjamin Block <bblock@linux.ibm.com> |
| Signed-off-by: Martin K. Petersen <martin.petersen@oracle.com> |
| Signed-off-by: Ben Hutchings <ben@decadent.org.uk> |
| --- |
| drivers/s390/scsi/zfcp_scsi.c | 2 ++ |
| 1 file changed, 2 insertions(+) |
| |
| --- a/drivers/s390/scsi/zfcp_scsi.c |
| +++ b/drivers/s390/scsi/zfcp_scsi.c |
| @@ -201,6 +201,7 @@ static int zfcp_scsi_eh_abort_handler(st |
| if (abrt_req) |
| break; |
| |
| + zfcp_dbf_scsi_abort("abrt_wt", scpnt, NULL); |
| zfcp_erp_wait(adapter); |
| ret = fc_block_scsi_eh(scpnt); |
| if (ret) { |
| @@ -297,6 +298,7 @@ static int zfcp_task_mgmt_function(struc |
| if (fsf_req) |
| break; |
| |
| + zfcp_dbf_scsi_devreset("wait", scpnt, tm_flags, NULL); |
| zfcp_erp_wait(adapter); |
| ret = fc_block_scsi_eh(scpnt); |
| if (ret) { |