From 5994844195e9a2ead1d1f5ba65b653debb9f1e35 Mon Sep 17 00:00:00 2001 From: Chinmaya Kajagar Date: Tue, 28 Jul 2026 06:48:55 +0200 Subject: [PATCH 1/3] scsi: zfcp: Enhance fsf status read buffer tracing SRB trace records are logged through hba trace event zfcp_dbf_hba_fsf_uss. Presently, this trace event has few missing fields in fsf status read buffer trace records. To fully trace incoming fsf status read buffer (SRB), the remaining fields are needed to be added to zfcp_dbf_hba_uss structure. Append all the remaining SRB fields to the existing unsolicited status trace records. Extend driver to get 3 bytes source id s_id value from fsf status read buffer's existing reserved field res3. To display this change, we also change the external tool `zfcpdbf` in the s390-tools package. zfcpdbf tool trace example for HBA area after changes: Timestamp : 2025-08-22-05:52:04:171750 Area : HBA Subarea : 00 Level : 2 Exception : - CPU ID : 0003 Caller : 0x0000021e278c07c8 Record ID : 2 Tag : fssrh_4 Description : fssrh_4 HBA, FSF unsolicited status Request ID : 0x0000000000004bfc Request status : 0x00000000 FSF cmnd : 0x00006305 FSF sequence no: 0x00000000 SRB stat type : 0x00000002 SRB stat sub : 0x00000000 SRB D_ID : 0x00fffffd SRB LUN : 0x0000000000000000 SRB q-design. : 0x0000000000000000 SRB length : 0x0000004c SRB res1 : 00000000 SRB res2 : 00 SRB class : 0x00000000 SRB res3 : 00 SRB S_ID : 0x0033c048 SRB res4 : 00000000 00000000 00000000 00000000 00000000 SRB pay length : 12 Payload time : 2025-08-22-05:52:04:171743 SRB info : 6104000c 0033c024 0033c02e Reviewed-by: Benjamin Block Signed-off-by: Chinmaya Kajagar Link: https://patch.msgid.link/20260728044857.2532646-2-niharp@linux.ibm.com Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 7 +++++++ drivers/s390/scsi/zfcp_dbf.h | 14 ++++++++++++++ drivers/s390/scsi/zfcp_fsf.h | 4 +++- 3 files changed, 24 insertions(+), 1 deletion(-) diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 71f625926ae1..89b859176b8b 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -220,6 +220,13 @@ void zfcp_dbf_hba_fsf_uss(char *tag, struct zfcp_fsf_req *req) rec->u.uss.lun = srb->fcp_lun; memcpy(&rec->u.uss.queue_designator, &srb->queue_designator, sizeof(rec->u.uss.queue_designator)); + rec->u.uss.length = srb->length; + rec->u.uss.res1 = srb->res1; + rec->u.uss.res2 = srb->res2; + rec->u.uss.class = srb->class; + rec->u.uss.res3 = srb->res3; + rec->u.uss.s_id = ntoh24(srb->s_id); + memcpy(&rec->u.uss.res4, &srb->res4, sizeof(rec->u.uss.res4)); /* status read buffer payload length */ rec->pl_len = (!srb->length) ? 0 : srb->length - diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index 4d1435c573bc..44ebad8c761c 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -149,6 +149,13 @@ struct zfcp_dbf_hba_res { * @d_id: destination ID * @lun: logical unit number * @queue_designator: queue designator + * @length: buffer length + * @res1: reserved field 1 + * @res2: reserved field 2 + * @class: class of service + * @res3: reserved field 3 + * @s_id: source ID + * @res4: reserved field 4 */ struct zfcp_dbf_hba_uss { u32 status_type; @@ -156,6 +163,13 @@ struct zfcp_dbf_hba_uss { u32 d_id; u64 lun; u64 queue_designator; + u32 length; + u32 res1; + u8 res2; + u32 class; + u8 res3; + u32 s_id; + u8 res4[20]; } __packed; /** diff --git a/drivers/s390/scsi/zfcp_fsf.h b/drivers/s390/scsi/zfcp_fsf.h index 5e6b601af980..4b92e85ec71d 100644 --- a/drivers/s390/scsi/zfcp_fsf.h +++ b/drivers/s390/scsi/zfcp_fsf.h @@ -246,7 +246,9 @@ struct fsf_status_read_buffer { u8 d_id[3]; u32 class; u64 fcp_lun; - u8 res3[24]; + u8 res3; + u8 s_id[3]; + u8 res4[20]; union { u8 data[FSF_STATUS_READ_PAYLOAD_SIZE]; u32 word[FSF_STATUS_READ_PAYLOAD_SIZE/sizeof(u32)]; From 3efec904df6f7b0ca9e6267e9aea543402f01886 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Tue, 28 Jul 2026 06:48:56 +0200 Subject: [PATCH 2/3] scsi: zfcp: Trace PLOGI and PRLI within open port response as payload The FCP channel optionally returns the content of PLOGI and PRLI within open port response. This information is needed to debug unexpected open port responses. Pack both PLOGI and PRLI information back-to-back into a PAYload trace record of type "fsf_els" within existing HBA trace record. The length of both parts, and thus also the offset of the second part, are added to the corresponding HBA trace record. Be extra careful regarding bounds checking. Since auto port scan in multi-initiator zoning environments can cause a lot of failed open port responses and trace is enabled by default in the HBA trace area, chose a trace level 4 above the default of 3 for the corresponding PAYload trace record to contain PLOGI/PRLI data. This way, it avoids flooding the PAY area by default. In the spirit of commit 35f040df97fa ("zfcp: retain trace level for SCSI and HBA FSF response records"), pass the level here. For this, introduce an additional argument 'level' for zfcp_dbf_pl_write(). zfcpdbf tool partial trace example with PLOGI/PRLI log info after changes: PLOGI length : 116 PRLI length : 20 Payload time : 2026-01-29-06:19:15:626629 PLOGI/PRLIinfo : 02000000 00000000 80000800 000a0002 00000000 2002000e 1115c62f 2001000e 1115c62f 00000000 00000000 00000000 00000000 80000000 00000000 00000000 00000000 80000000 00000000 000a0000 00010000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 02100014 08002100 00000000 00000000 00000112 Reviewed-by: M Nikhil Reviewed-by: Nihar Panda Signed-off-by: Steffen Maier Co-developed-by: Chinmaya Kajagar Signed-off-by: Chinmaya Kajagar Link: https://patch.msgid.link/20260728044857.2532646-3-niharp@linux.ibm.com Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 37 ++++++++++++++++++++++++++++++------ drivers/s390/scsi/zfcp_dbf.h | 4 +++- 2 files changed, 34 insertions(+), 7 deletions(-) diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 89b859176b8b..4217b74baa38 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, 2023 + * Copyright IBM Corp. 2002, 2026 */ #define pr_fmt(fmt) "zfcp: " fmt @@ -35,13 +35,18 @@ static inline unsigned int zfcp_dbf_plen(unsigned int offset) return sizeof(struct zfcp_dbf_pay) + offset - ZFCP_DBF_PAY_MAX_REC; } +#define ZFCP_DBF_PAY_LEVEL 1 + static inline void zfcp_dbf_pl_write(struct zfcp_dbf *dbf, void *data, u16 length, char *area, - u64 req_id) + u64 req_id, int level) { struct zfcp_dbf_pay *pl = &dbf->pay_buf; u16 offset = 0, rec_length; + if (unlikely(!debug_level_enabled(dbf->pay, level))) + return; + spin_lock(&dbf->pay_lock); memset(pl, 0, sizeof(*pl)); pl->fsf_req_id = req_id; @@ -51,7 +56,7 @@ void zfcp_dbf_pl_write(struct zfcp_dbf *dbf, void *data, u16 length, char *area, rec_length = min((u16) ZFCP_DBF_PAY_MAX_REC, (u16) (length - offset)); memcpy(pl->data, data + offset, rec_length); - debug_event(dbf->pay, 1, pl, zfcp_dbf_plen(rec_length)); + debug_event(dbf->pay, level, pl, zfcp_dbf_plen(rec_length)); offset += rec_length; pl->counter++; @@ -96,7 +101,27 @@ void zfcp_dbf_hba_fsf_res(char *tag, int level, struct zfcp_fsf_req *req) rec->pl_len = q_head->log_length; zfcp_dbf_pl_write(dbf, (char *)q_pref + q_head->log_start, - rec->pl_len, "fsf_res", req->req_id); + rec->pl_len, "fsf_res", req->req_id, + ZFCP_DBF_PAY_LEVEL); + + if (q_head->fsf_command == FSF_QTCB_OPEN_PORT_WITH_DID) { + struct fsf_qtcb_bottom_support *q_bott = + &req->qtcb->bottom.support; + u32 plogi_len = 0, prli_len = 0; + + if (q_bott->els1_length) { + rec->u.res.plogi_len = q_bott->els1_length; + plogi_len = min_t(u32, q_bott->els1_length, + sizeof(q_bott->els)); + } + if (q_bott->els2_length) { + rec->u.res.prli_len = q_bott->els2_length; + prli_len = min_t(u32, q_bott->els2_length, + sizeof(q_bott->els) - plogi_len); + } + zfcp_dbf_pl_write(dbf, q_bott->els, plogi_len + prli_len, + "fsf_els", req->req_id, 4); + } debug_event(dbf->hba, level, rec, sizeof(*rec)); spin_unlock_irqrestore(&dbf->hba_lock, flags); @@ -234,7 +259,7 @@ void zfcp_dbf_hba_fsf_uss(char *tag, struct zfcp_fsf_req *req) if (rec->pl_len) zfcp_dbf_pl_write(dbf, srb->payload.data, rec->pl_len, - "fsf_uss", req->req_id); + "fsf_uss", req->req_id, ZFCP_DBF_PAY_LEVEL); log: debug_event(dbf->hba, level, rec, sizeof(*rec)); spin_unlock_irqrestore(&dbf->hba_lock, flags); @@ -739,7 +764,7 @@ void zfcp_dbf_scsi_common(char *tag, int level, struct scsi_device *sdev, min_t(u16, max_t(u16, rec->pl_len, ZFCP_DBF_PAY_MAX_REC), FSF_FCP_RSP_SIZE), - "fcp_riu", fsf->req_id); + "fcp_riu", fsf->req_id, ZFCP_DBF_PAY_LEVEL); } debug_event(dbf->scsi, level, rec, sizeof(*rec)); diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index 44ebad8c761c..c84f076440a8 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -3,7 +3,7 @@ * zfcp device driver * debug feature declarations * - * Copyright IBM Corp. 2008, 2020 + * Copyright IBM Corp. 2008, 2026 */ #ifndef ZFCP_DBF_H @@ -140,6 +140,8 @@ struct zfcp_dbf_hba_res { u8 fsf_status_qual[FSF_STATUS_QUALIFIER_SIZE]; u32 port_handle; u32 lun_handle; + u32 plogi_len; + u32 prli_len; } __packed; /** From dff03860a722e7f1d0a10bb22628d7896bd4b5ec Mon Sep 17 00:00:00 2001 From: Chinmaya Kajagar Date: Tue, 28 Jul 2026 06:48:57 +0200 Subject: [PATCH 3/3] scsi: zfcp: Trace return values of sysfs unit add store sysfs unit add failures are seen during FCP devices manual SCSI LUN scans, indicating the kernel cannot add a LUN, usually because the device is offline, already exists, no memory or the target port is incorrectly configured. Add a new trace to debug zfcp sysfs unit add failures with tag id ZFCP_DBF_HBA_UAS. This traces wwpn, fcp lun id, return value (error condition) and associated hba of the device. Typical unit add store failures as seen below example syslog messages, Feb 2 10:47:25 systemd-udevd[823]: rport-1:0-2: /etc/udev/ rules.d/41-zfcp-lun-0.0.50c0:0x500507680b26c449:0x01d2000000000000.rules:10 Failed to write ATTR{/sys/devices/css0/0.0.0015/0.0.50c0/0x500507680b26c449 /unit_add}, ignoring: File exists Feb 2 10:50:03 systemd-udevd[801]: rport-2:0-3: /etc/udev/ rules.d/41-zfcp-lun-0.0.50c0:0x500507680b26c448:0x01d2000000000000.rules:10 Failed to write ATTR{/sys/devices/css0/0.0.0015/0.0.50c0/0x500507680b26c448 /unit_add}, ignoring: Cannot allocate memory Example zfcpdbf traces for both the errors: Timestamp : 2026-03-05-07:28:34:029797 Area : HBA Subarea : 00 Level : 3 Exception : - CPU ID : 0002 Caller : 0x000001fe345e6d0e Record ID : 6 Tag : syuast2 Description : syuast2 HBA, unit add, failed, unable to add unit Request ID : 0x00000000ffffffff Request status : 0xffffffff FSF cmnd : 0xffffffff FSF sequence no: 0xffffffff WWPN : 0x500507680b25c448 LUN : 0x01d3000000000000 Return Value : 0xfffffff4 Timestamp : 2026-03-05-07:33:04:151807 <== the last record Area : HBA Subarea : 00 Level : 3 Exception : - CPU ID : 0002 Caller : 0x000001fe345e6d0e Record ID : 6 Tag : syuast2 Description : syuast2 HBA, unit add, failed, unable to add unit Request ID : 0x00000000ffffffff Request status : 0xffffffff FSF cmnd : 0xffffffff FSF sequence no: 0xffffffff WWPN : 0x500507680b25c449 LUN : 0x01d0000000000000 Return Value : 0xfffffff4 Link: https://patch.msgid.link/20260728044857.2532646-4-niharp@linux.ibm.com Signed-off-by: Chinmaya Kajagar Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 36 ++++++++++++++++++++++++++++++++++ drivers/s390/scsi/zfcp_dbf.h | 16 +++++++++++++++ drivers/s390/scsi/zfcp_ext.h | 4 +++- drivers/s390/scsi/zfcp_sysfs.c | 19 ++++++++++++------ 4 files changed, 68 insertions(+), 7 deletions(-) diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 4217b74baa38..81fb8af408e9 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -265,6 +265,42 @@ void zfcp_dbf_hba_fsf_uss(char *tag, struct zfcp_fsf_req *req) spin_unlock_irqrestore(&dbf->hba_lock, flags); } +/** + * zfcp_dbf_hba_uas - trace event for sysfs unit add store + * @tag: tag indicating which kind of unit add store condition occurred + * @level: debug trace level + * @adapter: pointer to struct zfcp_adapter + * @wwpn: remote port wwn + * @fcp_lun: FCP LUN + * @ret: return value + */ +void zfcp_dbf_hba_uas(char *tag, int level, struct zfcp_adapter *adapter, + u64 wwpn, u64 fcp_lun, int ret) +{ + struct zfcp_dbf *dbf = adapter->dbf; + struct zfcp_dbf_hba *rec = &dbf->hba_buf; + 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_UAS; + rec->fsf_req_id = ~0u; + rec->fsf_req_status = ~0u; + rec->fsf_cmd = ~0u; + rec->fsf_seq_no = ~0u; + rec->u.uas.wwpn = wwpn; + rec->u.uas.fcp_lun = fcp_lun; + rec->u.uas.ret = ret; + + debug_event(dbf->hba, level, rec, sizeof(*rec)); + spin_unlock_irqrestore(&dbf->hba_lock, flags); +} + /** * zfcp_dbf_hba_bit_err - trace event for bit error conditions * @tag: tag indicating which kind of bit error unsolicited status was received diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index c84f076440a8..79973fb24b1c 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -174,6 +174,18 @@ struct zfcp_dbf_hba_uss { u8 res4[20]; } __packed; +/** + * struct zfcp_dbf_hba_uas - trace record for sysfs unit add store + * @wwpn: remote port wwn + * @fcp_lun: FCP LUN + * @ret: return value + */ +struct zfcp_dbf_hba_uas { + u64 wwpn; + u64 fcp_lun; + u32 ret; +} __packed; + /** * struct zfcp_dbf_hba_fces - trace record for FC Endpoint Security * @req_issued: timestamp when request was issued @@ -200,6 +212,7 @@ struct zfcp_dbf_hba_fces { * @ZFCP_DBF_HBA_BIT: bit error trace record * @ZFCP_DBF_HBA_BASIC: basic adapter event, only trace tag, no other data * @ZFCP_DBF_HBA_FCES: FC Endpoint Security trace record + * @ZFCP_DBF_HBA_UAS: unit add store trace record */ enum zfcp_dbf_hba_id { ZFCP_DBF_HBA_RES = 1, @@ -207,6 +220,7 @@ enum zfcp_dbf_hba_id { ZFCP_DBF_HBA_BIT = 3, ZFCP_DBF_HBA_BASIC = 4, ZFCP_DBF_HBA_FCES = 5, + ZFCP_DBF_HBA_UAS = 6, }; /** @@ -223,6 +237,7 @@ enum zfcp_dbf_hba_id { * @u.uss: data for unsolicited status buffer * @u.be: data for bit error unsolicited status buffer * @u.fces: data for FC Endpoint Security + * @u.uas: data for unit add store */ struct zfcp_dbf_hba { u8 id; @@ -237,6 +252,7 @@ struct zfcp_dbf_hba { struct zfcp_dbf_hba_uss uss; struct fsf_bit_error_payload be; struct zfcp_dbf_hba_fces fces; + struct zfcp_dbf_hba_uas uas; } u; } __packed; diff --git a/drivers/s390/scsi/zfcp_ext.h b/drivers/s390/scsi/zfcp_ext.h index 9f5152b42b0e..40bd597fb4cd 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, 2023 + * Copyright IBM Corp. 2002, 2026 */ #ifndef ZFCP_EXT_H @@ -49,6 +49,8 @@ extern void zfcp_dbf_hba_fsf_fces(char *tag, const struct zfcp_fsf_req *req, 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_uas(char *tag, int level, struct zfcp_adapter *adapter, + u64 wwpn, u64 fcp_lun, int ret); 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_sysfs.c b/drivers/s390/scsi/zfcp_sysfs.c index 42423549e511..4f23d585d062 100644 --- a/drivers/s390/scsi/zfcp_sysfs.c +++ b/drivers/s390/scsi/zfcp_sysfs.c @@ -4,7 +4,7 @@ * * sysfs attributes. * - * Copyright IBM Corp. 2008, 2020 + * Copyright IBM Corp. 2008, 2026 */ #define pr_fmt(fmt) "zfcp: " fmt @@ -442,17 +442,24 @@ static ssize_t zfcp_sysfs_unit_add_store(struct device *dev, const char *buf, size_t count) { struct zfcp_port *port = container_of(dev, struct zfcp_port, dev); - u64 fcp_lun; - int retval; + struct zfcp_adapter *adapter = port->adapter; + u64 fcp_lun = 0; + int retval = -EINVAL; - if (kstrtoull(buf, 0, (unsigned long long *) &fcp_lun)) - return -EINVAL; + if (kstrtoull(buf, 0, (unsigned long long *)&fcp_lun)) { + zfcp_dbf_hba_uas("syuast1", 3, adapter, port->wwpn, + fcp_lun, retval); + return retval; + } flush_work(&port->rport_work); retval = zfcp_unit_add(port, fcp_lun); - if (retval) + if (retval) { + zfcp_dbf_hba_uas("syuast2", 3, adapter, port->wwpn, + fcp_lun, retval); return retval; + } return count; }