diff mbox series

[3/3] zfcp: trace when request remove fails after qdio send fails

Message ID 99b8246b2d71b63fa4f9c56333e2037502f7f5af.1677000450.git.bblock@linux.ibm.com (mailing list archive)
State Deferred
Headers show
Series [1/3] zfcp: make the type for accessing request hashtable buckets size_t | expand

Commit Message

Benjamin Block Feb. 21, 2023, 5:56 p.m. UTC
When we fail to send a FSF request in `zfcp_fsf_req_send()` when calling
`zfcp_qdio_send()` we try to remove the request object from our internal
hash table again to prevent keeping a stale memory reference. This
removal might still - very much theoretically - fail.

To store some evidence of when this happens add a new trace record for
this case; tag: `fsrsrmf`.
    We reuse the `ZFCP_DBF_HBA_RES` trace ID for this, but mark all
fields other then the request ID with ~0, to make fairly obvious that
these are invalid values. This faking has to be done because we don't
have a valid request object at this point, and can not safely access any
of the memory of the old object - we just failed to find it in our hash
table, so it might be gone already.

Here is an example of a decoded trace record:

    Timestamp      : 2023-02-17-13:09:12:748140
    Area           : HBA
    Subarea        : 1
    Level          : -
    Exception      : 000003ff7ff500c2
    CPU ID         : 0011
    Caller         : 0x0
    Record ID      : 1
    Tag            : fsrsrmf
    Request ID     : 0x0000000080126ab6
    Request status : 0xffffffff
    FSF cmnd       : 0xffffffff
    FSF sequence no: 0xffffffff
    FSF issued     : 2042-09-18-01:53:47:370495
    FSF stat       : 0xffffffff
    FSF stat qual  : ffffffff ffffffff ffffffff ffffffff
    Prot stat      : 0xffffffff
    Prot stat qual : ffffffff ffffffff ffffffff ffffffff
    Port handle    : 0xffffffff
    LUN handle     : 0xffffffff

This provides at least some basic evidence that this event happened, and
what object was affected.

Signed-off-by: Benjamin Block <bblock@linux.ibm.com>
Reviewed-by: Steffen Maier <maier@linux.ibm.com>
---
 drivers/s390/scsi/zfcp_dbf.c | 44 +++++++++++++++++++++++++++++++++++-
 drivers/s390/scsi/zfcp_ext.h |  5 +++-
 drivers/s390/scsi/zfcp_fsf.c |  7 ++++--
 3 files changed, 52 insertions(+), 4 deletions(-)
diff mbox series

Patch

diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c
index d28c55ae9f01..d904625afd40 100644
--- a/drivers/s390/scsi/zfcp_dbf.c
+++ b/drivers/s390/scsi/zfcp_dbf.c
@@ -4,7 +4,7 @@ 
  *
  * Debug traces for zfcp.
  *
- * Copyright IBM Corp. 2002, 2020
+ * Copyright IBM Corp. 2002, 2023
  */
 
 #define KMSG_COMPONENT "zfcp"
@@ -145,6 +145,48 @@  void zfcp_dbf_hba_fsf_fces(char *tag, const struct zfcp_fsf_req *req, u64 wwpn,
 	spin_unlock_irqrestore(&dbf->hba_lock, flags);
 }
 
+/**
+ * zfcp_dbf_hba_fsf_reqid - trace only the tag and a request ID
+ * @tag: tag documenting the source
+ * @level: trace level
+ * @adapter: adapter instance the request ID belongs to
+ * @req_id: the request ID to trace
+ */
+void zfcp_dbf_hba_fsf_reqid(const char *const tag, const int level,
+			    struct zfcp_adapter *const adapter,
+			    const u64 req_id)
+{
+	struct zfcp_dbf *const dbf = adapter->dbf;
+	struct zfcp_dbf_hba *const rec = &dbf->hba_buf;
+	struct zfcp_dbf_hba_res *const res = &rec->u.res;
+	unsigned long flags;
+
+	if (unlikely(!debug_level_enabled(dbf->hba, level)))
+		return;
+
+	spin_lock_irqsave(&dbf->hba_lock, flags);
+	memset(rec, 0, sizeof(*rec));
+
+	memcpy(rec->tag, tag, ZFCP_DBF_TAG_LEN);
+
+	rec->id = ZFCP_DBF_HBA_RES;
+	rec->fsf_req_id = req_id;
+	rec->fsf_req_status = ~0u;
+	rec->fsf_cmd = ~0u;
+	rec->fsf_seq_no = ~0u;
+
+	res->req_issued = ~0ull;
+	res->prot_status = ~0u;
+	memset(res->prot_status_qual, 0xff, sizeof(res->prot_status_qual));
+	res->fsf_status = ~0u;
+	memset(res->fsf_status_qual, 0xff, sizeof(res->fsf_status_qual));
+	res->port_handle = ~0u;
+	res->lun_handle = ~0u;
+
+	debug_event(dbf->hba, level, rec, sizeof(*rec));
+	spin_unlock_irqrestore(&dbf->hba_lock, flags);
+}
+
 /**
  * zfcp_dbf_hba_fsf_uss - trace event for an unsolicited status buffer
  * @tag: tag indicating which kind of unsolicited status has been received
diff --git a/drivers/s390/scsi/zfcp_ext.h b/drivers/s390/scsi/zfcp_ext.h
index c302cbb18a55..9f5152b42b0e 100644
--- a/drivers/s390/scsi/zfcp_ext.h
+++ b/drivers/s390/scsi/zfcp_ext.h
@@ -4,7 +4,7 @@ 
  *
  * External function declarations.
  *
- * Copyright IBM Corp. 2002, 2020
+ * Copyright IBM Corp. 2002, 2023
  */
 
 #ifndef ZFCP_EXT_H
@@ -46,6 +46,9 @@  extern void zfcp_dbf_hba_fsf_res(char *, int, struct zfcp_fsf_req *);
 extern void zfcp_dbf_hba_fsf_fces(char *tag, const struct zfcp_fsf_req *req,
 				  u64 wwpn, u32 fc_security_old,
 				  u32 fc_security_new);
+extern void zfcp_dbf_hba_fsf_reqid(const char *const tag, const int level,
+				   struct zfcp_adapter *const adapter,
+				   const u64 req_id);
 extern void zfcp_dbf_hba_bit_err(char *, struct zfcp_fsf_req *);
 extern void zfcp_dbf_hba_def_err(struct zfcp_adapter *, u64, u16, void **);
 extern void zfcp_dbf_san_req(char *, struct zfcp_fsf_req *, u32);
diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c
index 71eabcc26cbb..ceed1b6f7cb6 100644
--- a/drivers/s390/scsi/zfcp_fsf.c
+++ b/drivers/s390/scsi/zfcp_fsf.c
@@ -4,7 +4,7 @@ 
  *
  * Implementation of FSF commands.
  *
- * Copyright IBM Corp. 2002, 2020
+ * Copyright IBM Corp. 2002, 2023
  */
 
 #define KMSG_COMPONENT "zfcp"
@@ -892,8 +892,11 @@  static int zfcp_fsf_req_send(struct zfcp_fsf_req *req)
 	req->issued = get_tod_clock();
 	if (zfcp_qdio_send(qdio, &req->qdio_req)) {
 		del_timer_sync(&req->timer);
+
 		/* lookup request again, list might have changed */
-		zfcp_reqlist_find_rm(adapter->req_list, req_id);
+		if (zfcp_reqlist_find_rm(adapter->req_list, req_id) == NULL)
+			zfcp_dbf_hba_fsf_reqid("fsrsrmf", 1, adapter, req_id);
+
 		zfcp_erp_adapter_reopen(adapter, 0, "fsrs__1");
 		return -EIO;
 	}