@@ -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
@@ -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);
@@ -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;
}
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(-)