From bd77befa5bcff8c51613de271913639edf85fbc2 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:44 +0200 Subject: zfcp: fix fc_host port_type with NPIV For an NPIV-enabled FCP device, zfcp can erroneously show "NPort (fabric via point-to-point)" instead of "NPIV VPORT" for the port_type sysfs attribute of the corresponding fc_host. s390-tools that can be affected are dbginfo.sh and ziomon. zfcp_fsf_exchange_config_evaluate() ignores fsf_qtcb_bottom_config.connection_features indicating NPIV and only sets fc_host_port_type to FC_PORTTYPE_NPORT if fsf_qtcb_bottom_config.fc_topology is FSF_TOPO_FABRIC. Only the independent zfcp_fsf_exchange_port_evaluate() evaluates connection_features to overwrite fc_host_port_type to FC_PORTTYPE_NPIV in case of NPIV. Code was introduced with upstream kernel 2.6.30 commit 0282985da5923fa6365adcc1a1586ae0c13c1617 ("[SCSI] zfcp: Report fc_host_port_type as NPIV"). This works during FCP device recovery (such as set online) because it performs FSF_QTCB_EXCHANGE_CONFIG_DATA followed by FSF_QTCB_EXCHANGE_PORT_DATA in sequence. However, the zfcp-specific scsi host sysfs attributes "requests", "megabytes", or "seconds_active" trigger only zfcp_fsf_exchange_config_evaluate() resetting fc_host port_type to FC_PORTTYPE_NPORT despite NPIV. The zfcp-specific scsi host sysfs attribute "utilization" triggers only zfcp_fsf_exchange_port_evaluate() correcting the fc_host port_type again in case of NPIV. Evaluate fsf_qtcb_bottom_config.connection_features in zfcp_fsf_exchange_config_evaluate() where it belongs to. Signed-off-by: Steffen Maier Fixes: 0282985da592 ("[SCSI] zfcp: Report fc_host_port_type as NPIV") Cc: #2.6.30+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_fsf.c | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c index 522a633c866a..84353f45cfe6 100644 --- a/drivers/s390/scsi/zfcp_fsf.c +++ b/drivers/s390/scsi/zfcp_fsf.c @@ -3,7 +3,7 @@ * * Implementation of FSF commands. * - * Copyright IBM Corp. 2002, 2013 + * Copyright IBM Corp. 2002, 2015 */ #define KMSG_COMPONENT "zfcp" @@ -508,7 +508,10 @@ static int zfcp_fsf_exchange_config_evaluate(struct zfcp_fsf_req *req) fc_host_port_type(shost) = FC_PORTTYPE_PTP; break; case FSF_TOPO_FABRIC: - fc_host_port_type(shost) = FC_PORTTYPE_NPORT; + if (bottom->connection_features & FSF_FEATURE_NPIV_MODE) + fc_host_port_type(shost) = FC_PORTTYPE_NPIV; + else + fc_host_port_type(shost) = FC_PORTTYPE_NPORT; break; case FSF_TOPO_AL: fc_host_port_type(shost) = FC_PORTTYPE_NLPORT; @@ -613,7 +616,6 @@ static void zfcp_fsf_exchange_port_evaluate(struct zfcp_fsf_req *req) if (adapter->connection_features & FSF_FEATURE_NPIV_MODE) { fc_host_permanent_port_name(shost) = bottom->wwpn; - fc_host_port_type(shost) = FC_PORTTYPE_NPIV; } else fc_host_permanent_port_name(shost) = fc_host_port_name(shost); fc_host_maxframe_size(shost) = bottom->maximum_frame_size; -- cgit v1.2.3-59-g8ed1b From 70369f8e15b220f50a16348c79a61d3f7054813c Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:45 +0200 Subject: zfcp: fix ELS/GS request&response length for hardware data router In the hardware data router case, introduced with kernel 3.2 commit 86a9668a8d29 ("[SCSI] zfcp: support for hardware data router") the ELS/GS request&response length needs to be initialized as in the chained SBAL case. Otherwise, the FCP channel rejects ELS requests with FSF_REQUEST_SIZE_TOO_LARGE. Such ELS requests can be issued by user space through BSG / HBA API, or zfcp itself uses ADISC ELS for remote port link test on RSCN. The latter can cause a short path outage due to unnecessary remote target port recovery because the always failing ADISC cannot detect extremely short path interruptions beyond the local FCP channel. Below example is decoded with zfcpdbf from s390-tools: Timestamp : ... Area : SAN Subarea : 00 Level : 1 Exception : - CPU id : .. Caller : zfcp_dbf_san_req+0408 Record id : 1 Tag : fssels1 Request id : 0x Destination ID : 0x00 Payload info : 52000000 00000000 [ADISC] 00 00000000 00000000 00000000 00000000 00000000 Timestamp : ... Area : HBA Subarea : 00 Level : 1 Exception : - CPU id : .. Caller : zfcp_dbf_hba_fsf_res+0740 Record id : 1 Tag : fs_ferr Request id : 0x Request status : 0x00000010 FSF cmnd : 0x0000000b [FSF_QTCB_SEND_ELS] FSF sequence no: 0x... FSF issued : ... FSF stat : 0x00000061 [FSF_REQUEST_SIZE_TOO_LARGE] FSF stat qual : 00000000 00000000 00000000 00000000 Prot stat : 0x00000100 Prot stat qual : 00000000 00000000 00000000 00000000 Signed-off-by: Steffen Maier Fixes: 86a9668a8d29 ("[SCSI] zfcp: support for hardware data router") Cc: # 3.2+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_fsf.c | 4 ++++ 1 file changed, 4 insertions(+) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c index 84353f45cfe6..96d35a7209fa 100644 --- a/drivers/s390/scsi/zfcp_fsf.c +++ b/drivers/s390/scsi/zfcp_fsf.c @@ -984,8 +984,12 @@ static int zfcp_fsf_setup_ct_els_sbals(struct zfcp_fsf_req *req, if (zfcp_adapter_multi_buffer_active(adapter)) { if (zfcp_qdio_sbals_from_sg(qdio, &req->qdio_req, sg_req)) return -EIO; + qtcb->bottom.support.req_buf_length = + zfcp_qdio_real_bytes(sg_req); if (zfcp_qdio_sbals_from_sg(qdio, &req->qdio_req, sg_resp)) return -EIO; + qtcb->bottom.support.resp_buf_length = + zfcp_qdio_real_bytes(sg_resp); zfcp_qdio_set_data_div(qdio, &req->qdio_req, zfcp_qdio_sbale_count(sg_req)); -- cgit v1.2.3-59-g8ed1b From 4eeaa4f3f1d6c47b69f70e222297a4df4743363e Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:46 +0200 Subject: zfcp: close window with unblocked rport during rport gone On a successful end of reopen port forced, zfcp_erp_strategy_followup_success() re-uses the port erp_action and the subsequent zfcp_erp_action_cleanup() now sees ZFCP_ERP_SUCCEEDED with erp_action->action==ZFCP_ERP_ACTION_REOPEN_PORT instead of ZFCP_ERP_ACTION_REOPEN_PORT_FORCED but must not perform zfcp_scsi_schedule_rport_register(). We can detect this because the fresh port reopen erp_action is in its very first step ZFCP_ERP_STEP_UNINITIALIZED. Otherwise this opens a time window with unblocked rport (until the followup port reopen recovery would block it again). If a scsi_cmnd timeout occurs during this time window fc_timed_out() cannot work as desired and such command would indeed time out and trigger scsi_eh. This prevents a clean and timely path failover. This should not happen if the path issue can be recovered on FC transport layer such as path issues involving RSCNs. Also, unnecessary and repeated DID_IMM_RETRY for pending and undesired new requests occur because internally zfcp still has its zfcp_port blocked. As follow-on errors with scsi_eh, it can cause, in the worst case, permanently lost paths due to one of: sd : [] Medium access timeout failure. Offlining disk! sd : Device offlined - not ready after error recovery For fix validation and to aid future debugging with other recoveries we now also trace (un)blocking of rports. Signed-off-by: Steffen Maier Fixes: 5767620c383a ("[SCSI] zfcp: Do not unblock rport from REOPEN_PORT_FORCED") Fixes: a2fa0aede07c ("[SCSI] zfcp: Block FC transport rports early on errors") Fixes: 5f852be9e11d ("[SCSI] zfcp: Fix deadlock between zfcp ERP and SCSI") Fixes: 338151e06608 ("[SCSI] zfcp: make use of fc_remote_port_delete when target port is unavailable") Fixes: 3859f6a248cb ("[PATCH] zfcp: add rports to enable scsi_add_device to work again") Cc: #2.6.32+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.h | 7 ++++++- drivers/s390/scsi/zfcp_erp.c | 12 +++++++++--- drivers/s390/scsi/zfcp_scsi.c | 8 +++++++- 3 files changed, 22 insertions(+), 5 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index 0be3d48681ae..7901deb4ba89 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -2,7 +2,7 @@ * zfcp device driver * debug feature declarations * - * Copyright IBM Corp. 2008, 2010 + * Copyright IBM Corp. 2008, 2015 */ #ifndef ZFCP_DBF_H @@ -17,6 +17,11 @@ #define ZFCP_DBF_INVALID_LUN 0xFFFFFFFFFFFFFFFFull +enum zfcp_dbf_pseudo_erp_act_type { + ZFCP_PSEUDO_ERP_ACTION_RPORT_ADD = 0xff, + ZFCP_PSEUDO_ERP_ACTION_RPORT_DEL = 0xfe, +}; + /** * struct zfcp_dbf_rec_trigger - trace record for triggered recovery action * @ready: number of ready recovery actions diff --git a/drivers/s390/scsi/zfcp_erp.c b/drivers/s390/scsi/zfcp_erp.c index 3fb410977014..a59d678125bd 100644 --- a/drivers/s390/scsi/zfcp_erp.c +++ b/drivers/s390/scsi/zfcp_erp.c @@ -3,7 +3,7 @@ * * Error Recovery Procedures (ERP). * - * Copyright IBM Corp. 2002, 2010 + * Copyright IBM Corp. 2002, 2015 */ #define KMSG_COMPONENT "zfcp" @@ -1217,8 +1217,14 @@ static void zfcp_erp_action_cleanup(struct zfcp_erp_action *act, int result) break; case ZFCP_ERP_ACTION_REOPEN_PORT: - if (result == ZFCP_ERP_SUCCEEDED) - zfcp_scsi_schedule_rport_register(port); + /* This switch case might also happen after a forced reopen + * was successfully done and thus overwritten with a new + * non-forced reopen at `ersfs_2'. In this case, we must not + * do the clean-up of the non-forced version. + */ + if (act->step != ZFCP_ERP_STEP_UNINITIALIZED) + if (result == ZFCP_ERP_SUCCEEDED) + zfcp_scsi_schedule_rport_register(port); /* fall through */ case ZFCP_ERP_ACTION_REOPEN_PORT_FORCED: put_device(&port->dev); diff --git a/drivers/s390/scsi/zfcp_scsi.c b/drivers/s390/scsi/zfcp_scsi.c index b3c6ff49103b..9069f98a1817 100644 --- a/drivers/s390/scsi/zfcp_scsi.c +++ b/drivers/s390/scsi/zfcp_scsi.c @@ -3,7 +3,7 @@ * * Interface to Linux SCSI midlayer. * - * Copyright IBM Corp. 2002, 2013 + * Copyright IBM Corp. 2002, 2015 */ #define KMSG_COMPONENT "zfcp" @@ -556,6 +556,9 @@ static void zfcp_scsi_rport_register(struct zfcp_port *port) ids.port_id = port->d_id; ids.roles = FC_RPORT_ROLE_FCP_TARGET; + zfcp_dbf_rec_trig("scpaddy", port->adapter, port, NULL, + ZFCP_PSEUDO_ERP_ACTION_RPORT_ADD, + ZFCP_PSEUDO_ERP_ACTION_RPORT_ADD); rport = fc_remote_port_add(port->adapter->scsi_host, 0, &ids); if (!rport) { dev_err(&port->adapter->ccw_device->dev, @@ -577,6 +580,9 @@ static void zfcp_scsi_rport_block(struct zfcp_port *port) struct fc_rport *rport = port->rport; if (rport) { + zfcp_dbf_rec_trig("scpdely", port->adapter, port, NULL, + ZFCP_PSEUDO_ERP_ACTION_RPORT_DEL, + ZFCP_PSEUDO_ERP_ACTION_RPORT_DEL); fc_remote_port_delete(rport); port->rport = NULL; } -- cgit v1.2.3-59-g8ed1b From 35f040df97fa0e94c7851c054ec71533c88b4b81 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:47 +0200 Subject: zfcp: retain trace level for SCSI and HBA FSF response records While retaining the actual filtering according to trace level, the following commits started to write such filtered records with a hardcoded record level of 1 instead of the actual record level: commit 250a1352b95e1db3216e5c5d4f4365bea5122f4a ("[SCSI] zfcp: Redesign of the debug tracing for SCSI records.") commit a54ca0f62f953898b05549391ac2a8a4dad6482b ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") Now we can distinguish written records again for offline level filtering. Signed-off-by: Steffen Maier Fixes: 250a1352b95e ("[SCSI] zfcp: Redesign of the debug tracing for SCSI records.") Fixes: a54ca0f62f95 ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") Cc: #2.6.38+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 11 ++++++----- drivers/s390/scsi/zfcp_dbf.h | 4 ++-- drivers/s390/scsi/zfcp_ext.h | 7 ++++--- 3 files changed, 12 insertions(+), 10 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 5d7fbe4e907e..2308253ddddc 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -3,7 +3,7 @@ * * Debug traces for zfcp. * - * Copyright IBM Corp. 2002, 2013 + * Copyright IBM Corp. 2002, 2015 */ #define KMSG_COMPONENT "zfcp" @@ -65,7 +65,7 @@ void zfcp_dbf_pl_write(struct zfcp_dbf *dbf, void *data, u16 length, char *area, * @tag: tag indicating which kind of unsolicited status has been received * @req: request for which a response was received */ -void zfcp_dbf_hba_fsf_res(char *tag, struct zfcp_fsf_req *req) +void zfcp_dbf_hba_fsf_res(char *tag, int level, struct zfcp_fsf_req *req) { struct zfcp_dbf *dbf = req->adapter->dbf; struct fsf_qtcb_prefix *q_pref = &req->qtcb->prefix; @@ -97,7 +97,7 @@ void zfcp_dbf_hba_fsf_res(char *tag, struct zfcp_fsf_req *req) rec->pl_len, "fsf_res", req->req_id); } - debug_event(dbf->hba, 1, rec, sizeof(*rec)); + debug_event(dbf->hba, level, rec, sizeof(*rec)); spin_unlock_irqrestore(&dbf->hba_lock, flags); } @@ -399,7 +399,8 @@ void zfcp_dbf_san_in_els(char *tag, struct zfcp_fsf_req *fsf) * @sc: pointer to struct scsi_cmnd * @fsf: pointer to struct zfcp_fsf_req */ -void zfcp_dbf_scsi(char *tag, struct scsi_cmnd *sc, struct zfcp_fsf_req *fsf) +void zfcp_dbf_scsi(char *tag, int level, struct scsi_cmnd *sc, + struct zfcp_fsf_req *fsf) { struct zfcp_adapter *adapter = (struct zfcp_adapter *) sc->device->host->hostdata[0]; @@ -442,7 +443,7 @@ void zfcp_dbf_scsi(char *tag, struct scsi_cmnd *sc, struct zfcp_fsf_req *fsf) } } - debug_event(dbf->scsi, 1, rec, sizeof(*rec)); + debug_event(dbf->scsi, level, rec, sizeof(*rec)); spin_unlock_irqrestore(&dbf->scsi_lock, flags); } diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index 7901deb4ba89..c879b54046ee 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -284,7 +284,7 @@ static inline void zfcp_dbf_hba_fsf_resp(char *tag, int level, struct zfcp_fsf_req *req) { if (debug_level_enabled(req->adapter->dbf->hba, level)) - zfcp_dbf_hba_fsf_res(tag, req); + zfcp_dbf_hba_fsf_res(tag, level, req); } /** @@ -323,7 +323,7 @@ void _zfcp_dbf_scsi(char *tag, int level, struct scsi_cmnd *scmd, scmd->device->host->hostdata[0]; if (debug_level_enabled(adapter->dbf->scsi, level)) - zfcp_dbf_scsi(tag, scmd, req); + zfcp_dbf_scsi(tag, level, scmd, req); } /** diff --git a/drivers/s390/scsi/zfcp_ext.h b/drivers/s390/scsi/zfcp_ext.h index 5b500652572b..fd03a943cde2 100644 --- a/drivers/s390/scsi/zfcp_ext.h +++ b/drivers/s390/scsi/zfcp_ext.h @@ -3,7 +3,7 @@ * * External function declarations. * - * Copyright IBM Corp. 2002, 2010 + * Copyright IBM Corp. 2002, 2015 */ #ifndef ZFCP_EXT_H @@ -36,7 +36,7 @@ extern void zfcp_dbf_rec_trig(char *, struct zfcp_adapter *, struct zfcp_port *, struct scsi_device *, u8, u8); extern void zfcp_dbf_rec_run(char *, struct zfcp_erp_action *); extern void zfcp_dbf_hba_fsf_uss(char *, struct zfcp_fsf_req *); -extern void zfcp_dbf_hba_fsf_res(char *, struct zfcp_fsf_req *); +extern void zfcp_dbf_hba_fsf_res(char *, int, struct zfcp_fsf_req *); extern void zfcp_dbf_hba_bit_err(char *, struct zfcp_fsf_req *); extern void zfcp_dbf_hba_berr(struct zfcp_dbf *, struct zfcp_fsf_req *); extern void zfcp_dbf_hba_def_err(struct zfcp_adapter *, u64, u16, void **); @@ -44,7 +44,8 @@ extern void zfcp_dbf_hba_basic(char *, struct zfcp_adapter *); extern void zfcp_dbf_san_req(char *, struct zfcp_fsf_req *, u32); extern void zfcp_dbf_san_res(char *, struct zfcp_fsf_req *); extern void zfcp_dbf_san_in_els(char *, struct zfcp_fsf_req *); -extern void zfcp_dbf_scsi(char *, struct scsi_cmnd *, struct zfcp_fsf_req *); +extern void zfcp_dbf_scsi(char *, int, struct scsi_cmnd *, + struct zfcp_fsf_req *); /* zfcp_erp.c */ extern void zfcp_erp_set_adapter_status(struct zfcp_adapter *, u32); -- cgit v1.2.3-59-g8ed1b From 0102a30a6ff60f4bb4c07358ca3b1f92254a6c25 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:48 +0200 Subject: zfcp: restore: Dont use 0 to indicate invalid LUN in rec trace bring back commit d21e9daa63e009ce5b87bbcaa6d11ce48e07bbbe ("[SCSI] zfcp: Dont use 0 to indicate invalid LUN in rec trace") which was lost with commit ae0904f60fab7cb20c48d32eefdd735e478b91fb ("[SCSI] zfcp: Redesign of the debug tracing for recovery actions.") Signed-off-by: Steffen Maier Fixes: ae0904f60fab ("[SCSI] zfcp: Redesign of the debug tracing for recovery actions.") Cc: #2.6.38+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 2308253ddddc..e6ff199f7572 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -241,7 +241,8 @@ static void zfcp_dbf_set_common(struct zfcp_dbf_rec *rec, if (sdev) { rec->lun_status = atomic_read(&sdev_to_zfcp(sdev)->status); rec->lun = zfcp_scsi_dev_lun(sdev); - } + } else + rec->lun = ZFCP_DBF_INVALID_LUN; } /** -- cgit v1.2.3-59-g8ed1b From d27a7cb91960cf1fdd11b10071e601828cbf4b1f Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:49 +0200 Subject: zfcp: trace on request for open and close of WKA port Since commit a54ca0f62f953898b05549391ac2a8a4dad6482b ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") HBA records no longer contain WWPN, D_ID, or LUN to reduce duplicate information which is already in REC records. In contrast to "regular" target ports, we don't use recovery to open WKA ports such as directory/nameserver, so we don't get REC records. Therefore, introduce pseudo REC running records without any actual recovery action but including D_ID of WKA port on open/close. Signed-off-by: Steffen Maier Fixes: a54ca0f62f95 ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") Cc: #2.6.38+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 32 ++++++++++++++++++++++++++++++++ drivers/s390/scsi/zfcp_ext.h | 1 + drivers/s390/scsi/zfcp_fsf.c | 8 ++++++-- 3 files changed, 39 insertions(+), 2 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index e6ff199f7572..df68a4df8cdb 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -321,6 +321,38 @@ void zfcp_dbf_rec_run(char *tag, struct zfcp_erp_action *erp) spin_unlock_irqrestore(&dbf->rec_lock, flags); } +/** + * zfcp_dbf_rec_run_wka - trace wka port event with info like running recovery + * @tag: identifier for event + * @wka_port: well known address port + * @req_id: request ID to correlate with potential HBA trace record + */ +void zfcp_dbf_rec_run_wka(char *tag, struct zfcp_fc_wka_port *wka_port, + u64 req_id) +{ + struct zfcp_dbf *dbf = wka_port->adapter->dbf; + struct zfcp_dbf_rec *rec = &dbf->rec_buf; + unsigned long flags; + + spin_lock_irqsave(&dbf->rec_lock, flags); + memset(rec, 0, sizeof(*rec)); + + rec->id = ZFCP_DBF_REC_RUN; + memcpy(rec->tag, tag, ZFCP_DBF_TAG_LEN); + rec->port_status = wka_port->status; + rec->d_id = wka_port->d_id; + rec->lun = ZFCP_DBF_INVALID_LUN; + + rec->u.run.fsf_req_id = req_id; + rec->u.run.rec_status = ~0; + rec->u.run.rec_step = ~0; + rec->u.run.rec_action = ~0; + rec->u.run.rec_count = ~0; + + debug_event(dbf->rec, 1, rec, sizeof(*rec)); + spin_unlock_irqrestore(&dbf->rec_lock, flags); +} + static inline void zfcp_dbf_san(char *tag, struct zfcp_dbf *dbf, void *data, u8 id, u16 len, u64 req_id, u32 d_id) diff --git a/drivers/s390/scsi/zfcp_ext.h b/drivers/s390/scsi/zfcp_ext.h index fd03a943cde2..c8fed9fa1cca 100644 --- a/drivers/s390/scsi/zfcp_ext.h +++ b/drivers/s390/scsi/zfcp_ext.h @@ -35,6 +35,7 @@ extern void zfcp_dbf_adapter_unregister(struct zfcp_adapter *); extern void zfcp_dbf_rec_trig(char *, struct zfcp_adapter *, struct zfcp_port *, struct scsi_device *, u8, u8); extern void zfcp_dbf_rec_run(char *, struct zfcp_erp_action *); +extern void zfcp_dbf_rec_run_wka(char *, struct zfcp_fc_wka_port *, u64); extern void zfcp_dbf_hba_fsf_uss(char *, struct zfcp_fsf_req *); extern void zfcp_dbf_hba_fsf_res(char *, int, struct zfcp_fsf_req *); extern void zfcp_dbf_hba_bit_err(char *, struct zfcp_fsf_req *); diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c index 96d35a7209fa..f56906f09bb3 100644 --- a/drivers/s390/scsi/zfcp_fsf.c +++ b/drivers/s390/scsi/zfcp_fsf.c @@ -1581,7 +1581,7 @@ out: int zfcp_fsf_open_wka_port(struct zfcp_fc_wka_port *wka_port) { struct zfcp_qdio *qdio = wka_port->adapter->qdio; - struct zfcp_fsf_req *req; + struct zfcp_fsf_req *req = NULL; int retval = -EIO; spin_lock_irq(&qdio->req_q_lock); @@ -1610,6 +1610,8 @@ int zfcp_fsf_open_wka_port(struct zfcp_fc_wka_port *wka_port) zfcp_fsf_req_free(req); out: spin_unlock_irq(&qdio->req_q_lock); + if (req && !IS_ERR(req)) + zfcp_dbf_rec_run_wka("fsowp_1", wka_port, req->req_id); return retval; } @@ -1634,7 +1636,7 @@ static void zfcp_fsf_close_wka_port_handler(struct zfcp_fsf_req *req) int zfcp_fsf_close_wka_port(struct zfcp_fc_wka_port *wka_port) { struct zfcp_qdio *qdio = wka_port->adapter->qdio; - struct zfcp_fsf_req *req; + struct zfcp_fsf_req *req = NULL; int retval = -EIO; spin_lock_irq(&qdio->req_q_lock); @@ -1663,6 +1665,8 @@ int zfcp_fsf_close_wka_port(struct zfcp_fc_wka_port *wka_port) zfcp_fsf_req_free(req); out: spin_unlock_irq(&qdio->req_q_lock); + if (req && !IS_ERR(req)) + zfcp_dbf_rec_run_wka("fscwp_1", wka_port, req->req_id); return retval; } -- cgit v1.2.3-59-g8ed1b From 7c964ffe586bc0c3d9febe9bf97a2e4b2866e5b7 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:50 +0200 Subject: zfcp: restore tracing of handle for port and LUN with HBA records This information was lost with commit a54ca0f62f953898b05549391ac2a8a4dad6482b ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") but is required to debug e.g. invalid handle situations. Signed-off-by: Steffen Maier Fixes: a54ca0f62f95 ("[SCSI] zfcp: Redesign of the debug tracing for HBA records.") Cc: #2.6.38+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 2 ++ drivers/s390/scsi/zfcp_dbf.h | 2 ++ 2 files changed, 4 insertions(+) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index df68a4df8cdb..ceb934c93232 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -85,6 +85,8 @@ void zfcp_dbf_hba_fsf_res(char *tag, int level, struct zfcp_fsf_req *req) rec->u.res.req_issued = req->issued; rec->u.res.prot_status = q_pref->prot_status; rec->u.res.fsf_status = q_head->fsf_status; + rec->u.res.port_handle = q_head->port_handle; + rec->u.res.lun_handle = q_head->lun_handle; memcpy(rec->u.res.prot_status_qual, &q_pref->prot_status_qual, FSF_PROT_STATUS_QUAL_SIZE); diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index c879b54046ee..6ee46f1f9e43 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -131,6 +131,8 @@ struct zfcp_dbf_hba_res { u8 prot_status_qual[FSF_PROT_STATUS_QUAL_SIZE]; u32 fsf_status; u8 fsf_status_qual[FSF_STATUS_QUALIFIER_SIZE]; + u32 port_handle; + u32 lun_handle; } __packed; /** -- cgit v1.2.3-59-g8ed1b From 771bf03537ddfa4a4dde62ef9dfbc82e4f77ab20 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:51 +0200 Subject: zfcp: fix D_ID field with actual value on tracing SAN responses With commit 2c55b750a884b86dea8b4cc5f15e1484cc47a25c ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") we lost the N_Port-ID where an ELS response comes from. With commit 7c7dc196814b9e1d5cc254dc579a5fa78ae524f7 ("[SCSI] zfcp: Simplify handling of ct and els requests") we lost the N_Port-ID where a CT response comes from. It's especially useful if the request SAN trace record with D_ID was already lost due to trace buffer wrap. GS uses an open WKA port handle and ELS just a D_ID, and only for ELS we could get D_ID from QTCB bottom via zfcp_fsf_req. To cover both cases, add a new field to zfcp_fsf_ct_els and fill it in on request to use in SAN response trace. Strictly speaking the D_ID on SAN response is the FC frame's S_ID. We don't need a field for the other end which is always us. Signed-off-by: Steffen Maier Fixes: 2c55b750a884 ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") Fixes: 7c7dc196814b ("[SCSI] zfcp: Simplify handling of ct and els requests") Cc: #2.6.38+ Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 2 +- drivers/s390/scsi/zfcp_fsf.c | 2 ++ drivers/s390/scsi/zfcp_fsf.h | 4 +++- 3 files changed, 6 insertions(+), 2 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index ceb934c93232..968897f5e1c6 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -407,7 +407,7 @@ void zfcp_dbf_san_res(char *tag, struct zfcp_fsf_req *fsf) length = (u16)(ct_els->resp->length + FC_CT_HDR_LEN); zfcp_dbf_san(tag, dbf, sg_virt(ct_els->resp), ZFCP_DBF_SAN_RES, length, - fsf->req_id, 0); + fsf->req_id, ct_els->d_id); } /** diff --git a/drivers/s390/scsi/zfcp_fsf.c b/drivers/s390/scsi/zfcp_fsf.c index f56906f09bb3..75f820ca17b7 100644 --- a/drivers/s390/scsi/zfcp_fsf.c +++ b/drivers/s390/scsi/zfcp_fsf.c @@ -1079,6 +1079,7 @@ int zfcp_fsf_send_ct(struct zfcp_fc_wka_port *wka_port, req->handler = zfcp_fsf_send_ct_handler; req->qtcb->header.port_handle = wka_port->handle; + ct->d_id = wka_port->d_id; req->data = ct; zfcp_dbf_san_req("fssct_1", req, wka_port->d_id); @@ -1175,6 +1176,7 @@ int zfcp_fsf_send_els(struct zfcp_adapter *adapter, u32 d_id, hton24(req->qtcb->bottom.support.d_id, d_id); req->handler = zfcp_fsf_send_els_handler; + els->d_id = d_id; req->data = els; zfcp_dbf_san_req("fssels1", req, d_id); diff --git a/drivers/s390/scsi/zfcp_fsf.h b/drivers/s390/scsi/zfcp_fsf.h index 57ae3ae1046d..be1c04b334c5 100644 --- a/drivers/s390/scsi/zfcp_fsf.h +++ b/drivers/s390/scsi/zfcp_fsf.h @@ -3,7 +3,7 @@ * * Interface to the FSF support functions. * - * Copyright IBM Corp. 2002, 2010 + * Copyright IBM Corp. 2002, 2015 */ #ifndef FSF_H @@ -436,6 +436,7 @@ struct zfcp_blk_drv_data { * @handler_data: data passed to handler function * @port: Optional pointer to port for zfcp internal ELS (only test link ADISC) * @status: used to pass error status to calling function + * @d_id: Destination ID of either open WKA port for CT or of D_ID for ELS */ struct zfcp_fsf_ct_els { struct scatterlist *req; @@ -444,6 +445,7 @@ struct zfcp_fsf_ct_els { void *handler_data; struct zfcp_port *port; int status; + u32 d_id; }; #endif /* FSF_H */ -- cgit v1.2.3-59-g8ed1b From 94db3725f049ead24c96226df4a4fb375b880a77 Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:52 +0200 Subject: zfcp: fix payload trace length for SAN request&response commit 2c55b750a884b86dea8b4cc5f15e1484cc47a25c ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") started to add FC_CT_HDR_LEN which made zfcp dump random data out of bounds for RSPN GS responses because u.rspn.rsp is the largest and last field in the union of struct zfcp_fc_req. Other request/response types only happened to stay within bounds due to the padding of the union or due to the trace capping of u.gspn.rsp to ZFCP_DBF_SAN_MAX_PAYLOAD. Timestamp : ... Area : SAN Subarea : 00 Level : 1 Exception : - CPU id : .. Caller : ... Record id : 2 Tag : fsscth2 Request id : 0x... Destination ID : 0x00fffffc Payload short : 01000000 fc020000 80020000 00000000 xxxxxxxx xxxxxxxx xxxxxxxx xxxxxxxx <=== 00000000 00000000 00000000 00000000 Payload length : 32 <=== struct zfcp_fc_req { [0] struct zfcp_fsf_ct_els ct_els; [56] struct scatterlist sg_req; [96] struct scatterlist sg_rsp; union { struct {req; rsp;} adisc; SIZE: 28+28= 56 struct {req; rsp;} gid_pn; SIZE: 24+20= 44 struct {rspsg; req;} gpn_ft; SIZE: 40*4+20=180 struct {req; rsp;} gspn; SIZE: 20+273= 293 struct {req; rsp;} rspn; SIZE: 277+16= 293 [136] } u; } SIZE: 432 Signed-off-by: Steffen Maier Fixes: 2c55b750a884 ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") Cc: #2.6.38+ Reviewed-by: Alexey Ishchuk Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index 968897f5e1c6..d8c0bfb40366 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -389,7 +389,7 @@ void zfcp_dbf_san_req(char *tag, struct zfcp_fsf_req *fsf, u32 d_id) struct zfcp_fsf_ct_els *ct_els = fsf->data; u16 length; - length = (u16)(ct_els->req->length + FC_CT_HDR_LEN); + length = (u16)(ct_els->req->length); zfcp_dbf_san(tag, dbf, sg_virt(ct_els->req), ZFCP_DBF_SAN_REQ, length, fsf->req_id, d_id); } @@ -405,7 +405,7 @@ void zfcp_dbf_san_res(char *tag, struct zfcp_fsf_req *fsf) struct zfcp_fsf_ct_els *ct_els = fsf->data; u16 length; - length = (u16)(ct_els->resp->length + FC_CT_HDR_LEN); + length = (u16)(ct_els->resp->length); zfcp_dbf_san(tag, dbf, sg_virt(ct_els->resp), ZFCP_DBF_SAN_RES, length, fsf->req_id, ct_els->d_id); } -- cgit v1.2.3-59-g8ed1b From aceeffbb59bb91404a0bda32a542d7ebf878433a Mon Sep 17 00:00:00 2001 From: Steffen Maier Date: Wed, 10 Aug 2016 18:30:53 +0200 Subject: zfcp: trace full payload of all SAN records (req,resp,iels) This was lost with commit 2c55b750a884b86dea8b4cc5f15e1484cc47a25c ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") but is necessary for problem determination, e.g. to see the currently active zone set during automatic port scan. For the large GPN_FT response (4 pages), save space by not dumping any empty residual entries. Signed-off-by: Steffen Maier Fixes: 2c55b750a884 ("[SCSI] zfcp: Redesign of the debug tracing for SAN records.") Cc: #2.6.38+ Reviewed-by: Alexey Ishchuk Reviewed-by: Benjamin Block Reviewed-by: Hannes Reinecke Signed-off-by: Martin K. Petersen --- drivers/s390/scsi/zfcp_dbf.c | 116 ++++++++++++++++++++++++++++++++++++++----- drivers/s390/scsi/zfcp_dbf.h | 1 + 2 files changed, 104 insertions(+), 13 deletions(-) (limited to 'drivers/s390/scsi') diff --git a/drivers/s390/scsi/zfcp_dbf.c b/drivers/s390/scsi/zfcp_dbf.c index d8c0bfb40366..637cf8973c9e 100644 --- a/drivers/s390/scsi/zfcp_dbf.c +++ b/drivers/s390/scsi/zfcp_dbf.c @@ -3,7 +3,7 @@ * * Debug traces for zfcp. * - * Copyright IBM Corp. 2002, 2015 + * Copyright IBM Corp. 2002, 2016 */ #define KMSG_COMPONENT "zfcp" @@ -356,12 +356,15 @@ void zfcp_dbf_rec_run_wka(char *tag, struct zfcp_fc_wka_port *wka_port, } static inline -void zfcp_dbf_san(char *tag, struct zfcp_dbf *dbf, void *data, u8 id, u16 len, - u64 req_id, u32 d_id) +void zfcp_dbf_san(char *tag, struct zfcp_dbf *dbf, + char *paytag, struct scatterlist *sg, u8 id, u16 len, + u64 req_id, u32 d_id, u16 cap_len) { struct zfcp_dbf_san *rec = &dbf->san_buf; u16 rec_len; unsigned long flags; + struct zfcp_dbf_pay *payload = &dbf->pay_buf; + u16 pay_sum = 0; spin_lock_irqsave(&dbf->san_lock, flags); memset(rec, 0, sizeof(*rec)); @@ -369,10 +372,41 @@ void zfcp_dbf_san(char *tag, struct zfcp_dbf *dbf, void *data, u8 id, u16 len, rec->id = id; rec->fsf_req_id = req_id; rec->d_id = d_id; - rec_len = min(len, (u16)ZFCP_DBF_SAN_MAX_PAYLOAD); - memcpy(rec->payload, data, rec_len); memcpy(rec->tag, tag, ZFCP_DBF_TAG_LEN); + rec->pl_len = len; /* full length even if we cap pay below */ + if (!sg) + goto out; + rec_len = min_t(unsigned int, sg->length, ZFCP_DBF_SAN_MAX_PAYLOAD); + memcpy(rec->payload, sg_virt(sg), rec_len); /* part of 1st sg entry */ + if (len <= rec_len) + goto out; /* skip pay record if full content in rec->payload */ + + /* if (len > rec_len): + * dump data up to cap_len ignoring small duplicate in rec->payload + */ + spin_lock_irqsave(&dbf->pay_lock, flags); + memset(payload, 0, sizeof(*payload)); + memcpy(payload->area, paytag, ZFCP_DBF_TAG_LEN); + payload->fsf_req_id = req_id; + payload->counter = 0; + for (; sg && pay_sum < cap_len; sg = sg_next(sg)) { + u16 pay_len, offset = 0; + + while (offset < sg->length && pay_sum < cap_len) { + pay_len = min((u16)ZFCP_DBF_PAY_MAX_REC, + (u16)(sg->length - offset)); + /* cap_len <= pay_sum < cap_len+ZFCP_DBF_PAY_MAX_REC */ + memcpy(payload->data, sg_virt(sg) + offset, pay_len); + debug_event(dbf->pay, 1, payload, + zfcp_dbf_plen(pay_len)); + payload->counter++; + offset += pay_len; + pay_sum += pay_len; + } + } + spin_unlock(&dbf->pay_lock); +out: debug_event(dbf->san, 1, rec, sizeof(*rec)); spin_unlock_irqrestore(&dbf->san_lock, flags); } @@ -389,9 +423,62 @@ void zfcp_dbf_san_req(char *tag, struct zfcp_fsf_req *fsf, u32 d_id) struct zfcp_fsf_ct_els *ct_els = fsf->data; u16 length; - length = (u16)(ct_els->req->length); - zfcp_dbf_san(tag, dbf, sg_virt(ct_els->req), ZFCP_DBF_SAN_REQ, length, - fsf->req_id, d_id); + length = (u16)zfcp_qdio_real_bytes(ct_els->req); + zfcp_dbf_san(tag, dbf, "san_req", ct_els->req, ZFCP_DBF_SAN_REQ, + length, fsf->req_id, d_id, length); +} + +static u16 zfcp_dbf_san_res_cap_len_if_gpn_ft(char *tag, + struct zfcp_fsf_req *fsf, + u16 len) +{ + struct zfcp_fsf_ct_els *ct_els = fsf->data; + struct fc_ct_hdr *reqh = sg_virt(ct_els->req); + struct fc_ns_gid_ft *reqn = (struct fc_ns_gid_ft *)(reqh + 1); + struct scatterlist *resp_entry = ct_els->resp; + struct fc_gpn_ft_resp *acc; + int max_entries, x, last = 0; + + if (!(memcmp(tag, "fsscth2", 7) == 0 + && ct_els->d_id == FC_FID_DIR_SERV + && reqh->ct_rev == FC_CT_REV + && reqh->ct_in_id[0] == 0 + && reqh->ct_in_id[1] == 0 + && reqh->ct_in_id[2] == 0 + && reqh->ct_fs_type == FC_FST_DIR + && reqh->ct_fs_subtype == FC_NS_SUBTYPE + && reqh->ct_options == 0 + && reqh->_ct_resvd1 == 0 + && reqh->ct_cmd == FC_NS_GPN_FT + /* reqh->ct_mr_size can vary so do not match but read below */ + && reqh->_ct_resvd2 == 0 + && reqh->ct_reason == 0 + && reqh->ct_explan == 0 + && reqh->ct_vendor == 0 + && reqn->fn_resvd == 0 + && reqn->fn_domain_id_scope == 0 + && reqn->fn_area_id_scope == 0 + && reqn->fn_fc4_type == FC_TYPE_FCP)) + return len; /* not GPN_FT response so do not cap */ + + acc = sg_virt(resp_entry); + max_entries = (reqh->ct_mr_size * 4 / sizeof(struct fc_gpn_ft_resp)) + + 1 /* zfcp_fc_scan_ports: bytes correct, entries off-by-one + * to account for header as 1st pseudo "entry" */; + + /* the basic CT_IU preamble is the same size as one entry in the GPN_FT + * response, allowing us to skip special handling for it - just skip it + */ + for (x = 1; x < max_entries && !last; x++) { + if (x % (ZFCP_FC_GPN_FT_ENT_PAGE + 1)) + acc++; + else + acc = sg_virt(++resp_entry); + + last = acc->fp_flags & FC_NS_FID_LAST; + } + len = min(len, (u16)(x * sizeof(struct fc_gpn_ft_resp))); + return len; /* cap after last entry */ } /** @@ -405,9 +492,10 @@ void zfcp_dbf_san_res(char *tag, struct zfcp_fsf_req *fsf) struct zfcp_fsf_ct_els *ct_els = fsf->data; u16 length; - length = (u16)(ct_els->resp->length); - zfcp_dbf_san(tag, dbf, sg_virt(ct_els->resp), ZFCP_DBF_SAN_RES, length, - fsf->req_id, ct_els->d_id); + length = (u16)zfcp_qdio_real_bytes(ct_els->resp); + zfcp_dbf_san(tag, dbf, "san_res", ct_els->resp, ZFCP_DBF_SAN_RES, + length, fsf->req_id, ct_els->d_id, + zfcp_dbf_san_res_cap_len_if_gpn_ft(tag, fsf, length)); } /** @@ -421,11 +509,13 @@ void zfcp_dbf_san_in_els(char *tag, struct zfcp_fsf_req *fsf) struct fsf_status_read_buffer *srb = (struct fsf_status_read_buffer *) fsf->data; u16 length; + struct scatterlist sg; length = (u16)(srb->length - offsetof(struct fsf_status_read_buffer, payload)); - zfcp_dbf_san(tag, dbf, srb->payload.data, ZFCP_DBF_SAN_ELS, length, - fsf->req_id, ntoh24(srb->d_id)); + sg_init_one(&sg, srb->payload.data, length); + zfcp_dbf_san(tag, dbf, "san_els", &sg, ZFCP_DBF_SAN_ELS, length, + fsf->req_id, ntoh24(srb->d_id), length); } /** diff --git a/drivers/s390/scsi/zfcp_dbf.h b/drivers/s390/scsi/zfcp_dbf.h index 6ee46f1f9e43..36d07584271d 100644 --- a/drivers/s390/scsi/zfcp_dbf.h +++ b/drivers/s390/scsi/zfcp_dbf.h @@ -115,6 +115,7 @@ struct zfcp_dbf_san { u32 d_id; #define ZFCP_DBF_SAN_MAX_PAYLOAD (FC_CT_HDR_LEN + 32) char payload[ZFCP_DBF_SAN_MAX_PAYLOAD]; + u16 pl_len; } __packed; /** -- cgit v1.2.3-59-g8ed1b