| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-Id: <20231211173617.932990-13-kartilak@cisco.com>
Date: Mon, 11 Dec 2023 09:36:16 -0800
From: Karan Tilak Kumar <kartilak@...co.com>
To: sebaddel@...co.com
Cc: arulponn@...co.com, djhawar@...co.com, gcboffa@...co.com,
mkai2@...co.com, satishkh@...co.com, jejb@...ux.ibm.com,
martin.petersen@...cle.com, linux-scsi@...r.kernel.org,
linux-kernel@...r.kernel.org,
Karan Tilak Kumar <kartilak@...co.com>,
Hannes Reinecke <hare@...e.de>
Subject: [PATCH v6 12/13] scsi: fnic: Improve logs and add support for multiqueue (MQ)
Improve existing logs by adding fnic number, hardware queue,
tag, and mqtag in the prints.
Add logs with the above elements for effective debugging.
Reviewed-by: Sesidhar Baddela <sebaddel@...co.com>
Reviewed-by: Arulprabhu Ponnusamy <arulponn@...co.com>
Tested-by: Karan Tilak Kumar <kartilak@...co.com>
Reviewed-by: Hannes Reinecke <hare@...e.de>
Signed-off-by: Karan Tilak Kumar <kartilak@...co.com>
---
Changes between v4 and v5:
Incorporate review comments from Martin:
Modify patch commits to include a "---" separator.
Changes between v2 and v3:
Incorporate the following review comment from Hannes:
Use fnic_num as an argument to FNIC_SCSI_DBG.
Modify definition of FNIC_SCSI_DBG.
Host number is still an argument since
FNIC_SCSI_DBG in turn uses shost_printk.
---
drivers/scsi/fnic/fnic.h | 6 +-
drivers/scsi/fnic/fnic_scsi.c | 288 ++++++++++++++++++----------------
2 files changed, 154 insertions(+), 140 deletions(-)
diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h
index 34de8f0aacb2..28f402932b3c 100644
--- a/drivers/scsi/fnic/fnic.h
+++ b/drivers/scsi/fnic/fnic.h
@@ -155,9 +155,11 @@ do { \
"fnic<%d>: %s: %d: " fmt, fnic_num,\
__func__, __LINE__, ##args);)
-#define FNIC_SCSI_DBG(kern_level, host, fmt, args...) \
+#define FNIC_SCSI_DBG(kern_level, host, fnic_num, fmt, args...) \
FNIC_CHECK_LOGGING(FNIC_SCSI_LOGGING, \
- shost_printk(kern_level, host, fmt, ##args);)
+ shost_printk(kern_level, host, \
+ "fnic<%d>: %s: %d: " fmt, fnic_num,\
+ __func__, __LINE__, ##args);)
#define FNIC_ISR_DBG(kern_level, host, fnic_num, fmt, args...) \
FNIC_CHECK_LOGGING(FNIC_ISR_LOGGING, \
diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c
index 42807e89859c..4d6db4509e75 100644
--- a/drivers/scsi/fnic/fnic_scsi.c
+++ b/drivers/scsi/fnic/fnic_scsi.c
@@ -211,12 +211,12 @@ int fnic_fw_reset_handler(struct fnic *fnic)
if (!ret) {
atomic64_inc(&fnic->fnic_stats.reset_stats.fw_resets);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Issued fw reset\n");
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "Issued fw reset\n");
} else {
fnic_clear_state_flags(fnic, FNIC_FLAGS_FWRESET);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Failed to issue fw reset\n");
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "Failed to issue fw reset\n");
}
return ret;
@@ -259,15 +259,15 @@ int fnic_flogi_reg_handler(struct fnic *fnic, u32 fc_id)
fc_id, gw_mac,
fnic->data_src_addr,
lp->r_a_tov, lp->e_d_tov);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"FLOGI FIP reg issued fcid %x src %pM dest %pM\n",
fc_id, fnic->data_src_addr, gw_mac);
} else {
fnic_queue_wq_copy_desc_flogi_reg(wq, SCSI_NO_TAG,
format, fc_id, gw_mac);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "FLOGI reg issued fcid %x map %d dest %pM\n",
- fc_id, fnic->ctlr.map_dest, gw_mac);
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "FLOGI reg issued fcid 0x%x map %d dest 0x%p\n",
+ fc_id, fnic->ctlr.map_dest, gw_mac);
}
atomic64_inc(&fnic->fnic_stats.fw_stats.active_fw_reqs);
@@ -342,7 +342,7 @@ static inline int fnic_queue_wq_copy_desc(struct fnic *fnic,
free_wq_copy_descs(fnic, wq, hwq);
if (unlikely(!vnic_wq_copy_desc_avail(wq))) {
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
"fnic_queue_wq_copy_desc failure - no descriptors\n");
atomic64_inc(&misc_stats->io_cpwq_alloc_failures);
return SCSI_MLQUEUE_HOST_BUSY;
@@ -408,24 +408,24 @@ int fnic_queuecommand(struct Scsi_Host *shost, struct scsi_cmnd *sc)
if (unlikely(fnic_chk_state_flags_locked(fnic, FNIC_FLAGS_IO_BLOCKED))) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: fnic IO blocked flags: 0x%lx. Returning SCSI_MLQUEUE_HOST_BUSY\n",
- fnic->fnic_num, __func__, __LINE__, fnic->state_flags);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "fnic IO blocked flags: 0x%lx. Returning SCSI_MLQUEUE_HOST_BUSY\n",
+ fnic->state_flags);
return SCSI_MLQUEUE_HOST_BUSY;
}
if (unlikely(fnic_chk_state_flags_locked(fnic, FNIC_FLAGS_FWRESET))) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: fnic flags: 0x%lx. Returning SCSI_MLQUEUE_HOST_BUSY\n",
- fnic->fnic_num, __func__, __LINE__, fnic->state_flags);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "fnic flags: 0x%lx. Returning SCSI_MLQUEUE_HOST_BUSY\n",
+ fnic->state_flags);
return SCSI_MLQUEUE_HOST_BUSY;
}
rport = starget_to_rport(scsi_target(sc->device));
if (!rport) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"returning DID_NO_CONNECT for IO as rport is NULL\n");
sc->result = DID_NO_CONNECT << 16;
done(sc);
@@ -435,7 +435,7 @@ int fnic_queuecommand(struct Scsi_Host *shost, struct scsi_cmnd *sc)
ret = fc_remote_port_chkready(rport);
if (ret) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"rport is not ready\n");
atomic64_inc(&fnic_stats->misc_stats.rport_not_ready);
sc->result = ret;
@@ -446,7 +446,7 @@ int fnic_queuecommand(struct Scsi_Host *shost, struct scsi_cmnd *sc)
rp = rport->dd_data;
if (!rp || rp->rp_state == RPORT_ST_DELETE) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"rport 0x%x removed, returning DID_NO_CONNECT\n",
rport->port_id);
@@ -458,7 +458,7 @@ int fnic_queuecommand(struct Scsi_Host *shost, struct scsi_cmnd *sc)
if (rp->rp_state != RPORT_ST_READY) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"rport 0x%x in state 0x%x, returning DID_IMM_RETRY\n",
rport->port_id, rp->rp_state);
@@ -469,9 +469,9 @@ int fnic_queuecommand(struct Scsi_Host *shost, struct scsi_cmnd *sc)
if (lp->state != LPORT_ST_READY || !(lp->link_up)) {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: state not ready: %d/link not up: %d Returning HOST_BUSY\n",
- fnic->fnic_num, __func__, __LINE__, lp->state, lp->link_up);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "state not ready: %d/link not up: %d Returning HOST_BUSY\n",
+ lp->state, lp->link_up);
return SCSI_MLQUEUE_HOST_BUSY;
}
@@ -636,15 +636,14 @@ static int fnic_fcpio_fw_reset_cmpl_handler(struct fnic *fnic,
if (fnic->state == FNIC_IN_FC_TRANS_ETH_MODE) {
/* Check status of reset completion */
if (!hdr_status) {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "reset cmpl success\n");
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "reset cmpl success\n");
/* Ready to send flogi out */
fnic->state = FNIC_IN_ETH_MODE;
} else {
- FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host,
- "fnic fw_reset : failed %s\n",
- fnic_fcpio_status_to_str(hdr_status));
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "reset failed with header status: %s\n",
+ fnic_fcpio_status_to_str(hdr_status));
/*
* Unable to change to eth mode, cannot send out flogi
@@ -657,10 +656,9 @@ static int fnic_fcpio_fw_reset_cmpl_handler(struct fnic *fnic,
ret = -1;
}
} else {
- FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host,
- "Unexpected state %s while processing"
- " reset cmpl\n", fnic_state_to_str(fnic->state));
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "Unexpected state while processing reset completion: %s\n",
+ fnic_state_to_str(fnic->state));
atomic64_inc(&reset_stats->fw_reset_failures);
ret = -1;
}
@@ -711,19 +709,19 @@ static int fnic_fcpio_flogi_reg_cmpl_handler(struct fnic *fnic,
/* Check flogi registration completion status */
if (!hdr_status) {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"flog reg succeeded\n");
fnic->state = FNIC_IN_FC_MODE;
} else {
FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host,
+ fnic->lport->host, fnic->fnic_num,
"fnic flogi reg :failed %s\n",
fnic_fcpio_status_to_str(hdr_status));
fnic->state = FNIC_IN_ETH_MODE;
ret = -1;
}
} else {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Unexpected fnic state %s while"
" processing flogi reg completion\n",
fnic_state_to_str(fnic->state));
@@ -834,22 +832,20 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, unsigned int cq_ind
hwq = blk_mq_unique_tag_to_hwq(mqtag);
if (hwq != cq_index) {
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
- fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag, cq_index);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: hdr status: %s icmnd completion on the wrong queue\n",
- fnic->fnic_num, __func__, __LINE__,
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
+ hwq, mqtag, tag, cq_index);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hdr status: %s icmnd completion on the wrong queue\n",
fnic_fcpio_status_to_str(hdr_status));
}
if (tag >= fnic->fnic_max_tag_id) {
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
- fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag, cq_index);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: hdr status: %s Out of range tag\n",
- fnic->fnic_num, __func__, __LINE__,
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
+ hwq, mqtag, tag, cq_index);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hdr status: %s Out of range tag\n",
fnic_fcpio_status_to_str(hdr_status));
return;
}
@@ -915,7 +911,7 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, unsigned int cq_ind
if(FCPIO_ABORTED == hdr_status)
fnic_priv(sc)->flags |= FNIC_IO_ABORTED;
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
"icmnd_cmpl abts pending "
"hdr status = %s tag = 0x%x sc = 0x%p "
"scsi_status = %x residual = %d\n",
@@ -1100,31 +1096,28 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
hwq = blk_mq_unique_tag_to_hwq(id & FNIC_TAG_MASK);
if (hwq != cq_index) {
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
- __func__, __LINE__, hwq, mqtag, tag, cq_index);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hdr status: %s ITMF completion on the wrong queue\n",
- __func__, __LINE__,
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
+ hwq, mqtag, tag, cq_index);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hdr status: %s ITMF completion on the wrong queue\n",
fnic_fcpio_status_to_str(hdr_status));
}
if (tag > fnic->fnic_max_tag_id) {
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
- __func__, __LINE__, hwq, mqtag, tag, cq_index);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hdr status: %s Tag out of range\n",
- __func__, __LINE__,
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
+ hwq, mqtag, tag, cq_index);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hdr status: %s Tag out of range\n",
fnic_fcpio_status_to_str(hdr_status));
return;
} else if ((tag == fnic->fnic_max_tag_id) && !(id & FNIC_TAG_DEV_RST)) {
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
- __func__, __LINE__, hwq, mqtag, tag, cq_index);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "%s: %d: hdr status: %s Tag out of range\n",
- __func__, __LINE__,
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x cq index: %d ",
+ hwq, mqtag, tag, cq_index);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hdr status: %s Tag out of range\n",
fnic_fcpio_status_to_str(hdr_status));
return;
}
@@ -1169,9 +1162,10 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
if ((id & FNIC_TAG_ABORT) && (id & FNIC_TAG_DEV_RST)) {
/* Abort and terminate completion of device reset req */
/* REVISIT : Add asserts about various flags */
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "dev reset abts cmpl recd. id %x status %s\n",
- id, fnic_fcpio_status_to_str(hdr_status));
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Abt/term completion received\n",
+ hwq, mqtag, tag,
+ fnic_fcpio_status_to_str(hdr_status));
fnic_priv(sc)->state = FNIC_IOREQ_ABTS_COMPLETE;
fnic_priv(sc)->abts_status = hdr_status;
fnic_priv(sc)->flags |= FNIC_DEV_RST_DONE;
@@ -1180,6 +1174,10 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
} else if (id & FNIC_TAG_ABORT) {
/* Completion of abort cmd */
+ shost_printk(KERN_DEBUG, fnic->lport->host,
+ "hwq: %d mqtag: 0x%x tag: 0x%x Abort header status: %s\n",
+ hwq, mqtag, tag,
+ fnic_fcpio_status_to_str(hdr_status));
switch (hdr_status) {
case FCPIO_SUCCESS:
break;
@@ -1191,7 +1189,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
&term_stats->terminate_fw_timeouts);
break;
case FCPIO_ITMF_REJECTED:
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
"abort reject recd. id %d\n",
(int)(id & FNIC_TAG_MASK));
break;
@@ -1226,7 +1224,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
if (!(fnic_priv(sc)->flags & (FNIC_IO_ABORTED | FNIC_IO_DONE)))
atomic64_inc(&misc_stats->no_icmnd_itmf_cmpls);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"abts cmpl recd. id %d status %s\n",
(int)(id & FNIC_TAG_MASK),
fnic_fcpio_status_to_str(hdr_status));
@@ -1239,9 +1237,14 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
if (io_req->abts_done) {
complete(io_req->abts_done);
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
+ shost_printk(KERN_INFO, fnic->lport->host,
+ "hwq: %d mqtag: 0x%x tag: 0x%x Waking up abort thread\n",
+ hwq, mqtag, tag);
} else {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "abts cmpl, completing IO\n");
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Completing IO\n",
+ hwq, mqtag,
+ tag, fnic_fcpio_status_to_str(hdr_status));
fnic_priv(sc)->io_req = NULL;
sc->result = (DID_ERROR << 16);
fnic->sw_copy_wq[hwq].io_req_table[tag] = NULL;
@@ -1269,6 +1272,10 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
}
} else if (id & FNIC_TAG_DEV_RST) {
/* Completion of device reset */
+ shost_printk(KERN_INFO, fnic->lport->host,
+ "hwq: %d mqtag: 0x%x tag: 0x%x DR hst: %s\n",
+ hwq, mqtag,
+ tag, fnic_fcpio_status_to_str(hdr_status));
fnic_priv(sc)->lr_status = hdr_status;
if (fnic_priv(sc)->state == FNIC_IOREQ_ABTS_PENDING) {
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
@@ -1277,11 +1284,10 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
sc->device->host->host_no, id, sc,
jiffies_to_msecs(jiffies - start_time),
desc, 0, fnic_flags_and_state(sc));
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Terminate pending "
- "dev reset cmpl recd. id %d status %s\n",
- (int)(id & FNIC_TAG_MASK),
- fnic_fcpio_status_to_str(hdr_status));
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Terminate pending\n",
+ hwq, mqtag,
+ tag, fnic_fcpio_status_to_str(hdr_status));
return;
}
if (fnic_priv(sc)->flags & FNIC_DEV_RST_TIMED_OUT) {
@@ -1291,7 +1297,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
sc->device->host->host_no, id, sc,
jiffies_to_msecs(jiffies - start_time),
desc, 0, fnic_flags_and_state(sc));
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"dev reset cmpl recd after time out. "
"id %d status %s\n",
(int)(id & FNIC_TAG_MASK),
@@ -1300,18 +1306,18 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
}
fnic_priv(sc)->state = FNIC_IOREQ_CMD_COMPLETE;
fnic_priv(sc)->flags |= FNIC_DEV_RST_DONE;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "dev reset cmpl recd. id %d status %s\n",
- (int)(id & FNIC_TAG_MASK),
- fnic_fcpio_status_to_str(hdr_status));
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x hst: %s DR completion received\n",
+ hwq, mqtag,
+ tag, fnic_fcpio_status_to_str(hdr_status));
if (io_req->dr_done)
complete(io_req->dr_done);
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
} else {
shost_printk(KERN_ERR, fnic->lport->host,
- "Unexpected itmf io state %s tag %x\n",
- fnic_ioreq_state_to_str(fnic_priv(sc)->state), id);
+ "%s: Unexpected itmf io state: hwq: %d tag 0x%x %s\n",
+ __func__, hwq, id, fnic_ioreq_state_to_str(fnic_priv(sc)->state));
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
}
@@ -1364,7 +1370,7 @@ static int fnic_fcpio_cmpl_handler(struct vnic_dev *vdev,
break;
default:
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"firmware completion type %d\n",
desc->hdr.type);
break;
@@ -1425,9 +1431,9 @@ static bool fnic_cleanup_io_iter(struct scsi_cmnd *sc, void *data)
io_req = fnic_priv(sc)->io_req;
if (!io_req) {
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
- FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host,
- "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x flags: 0x%x No ioreq. Returning\n",
- fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag, fnic_priv(sc)->flags);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d mqtag: 0x%x tag: 0x%x flags: 0x%x No ioreq. Returning\n",
+ hwq, mqtag, tag, fnic_priv(sc)->flags);
return true;
}
@@ -1462,9 +1468,9 @@ static bool fnic_cleanup_io_iter(struct scsi_cmnd *sc, void *data)
mempool_free(io_req, fnic->io_req_pool);
sc->result = DID_TRANSPORT_DISRUPTED << 16;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "fnic_cleanup_io: tag:0x%x : sc:0x%p duration = %lu DID_TRANSPORT_DISRUPTED\n",
- tag, sc, jiffies - start_time);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "mqtag:0x%x tag: 0x%x sc:0x%p duration = %lu DID_TRANSPORT_DISRUPTED\n",
+ mqtag, tag, sc, (jiffies - start_time));
if (atomic64_read(&fnic->io_cmpl_skip))
atomic64_dec(&fnic->io_cmpl_skip);
@@ -1538,7 +1544,7 @@ void fnic_wq_copy_cleanup_handler(struct vnic_wq_copy *wq,
wq_copy_cleanup_scsi_cmd:
sc->result = DID_NO_CONNECT << 16;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "wq_copy_cleanup_handler:"
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num, "wq_copy_cleanup_handler:"
" DID_NO_CONNECT\n");
FNIC_TRACE(fnic_wq_copy_cleanup_handler,
@@ -1578,7 +1584,7 @@ static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag,
if (!vnic_wq_copy_desc_avail(wq)) {
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
atomic_dec(&fnic->in_flight);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"fnic_queue_abort_io_req: failure: no descriptors\n");
atomic64_inc(&misc_stats->abts_cpwq_alloc_failures);
return 1;
@@ -1633,9 +1639,9 @@ static bool fnic_rport_abort_io_iter(struct scsi_cmnd *sc, void *data)
if ((fnic_priv(sc)->flags & FNIC_DEVICE_RESET) &&
!(fnic_priv(sc)->flags & FNIC_DEV_RST_ISSUED)) {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "fnic_rport_exch_reset dev rst not pending sc 0x%p\n",
- sc);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d abt_tag: 0x%x flags: 0x%x Device reset is not pending\n",
+ hwq, abt_tag, fnic_priv(sc)->flags);
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
return true;
}
@@ -1669,11 +1675,11 @@ static bool fnic_rport_abort_io_iter(struct scsi_cmnd *sc, void *data)
atomic64_inc(&reset_stats->device_reset_terminates);
abt_tag |= FNIC_TAG_DEV_RST;
}
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"fnic_rport_exch_reset dev rst sc 0x%p\n", sc);
BUG_ON(io_req->abts_done);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"fnic_rport_reset_exch: Issuing abts\n");
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
@@ -1691,6 +1697,9 @@ static bool fnic_rport_abort_io_iter(struct scsi_cmnd *sc, void *data)
* lun reset
*/
spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d abt_tag: 0x%x flags: 0x%x Queuing abort failed\n",
+ hwq, abt_tag, fnic_priv(sc)->flags);
if (fnic_priv(sc)->state == FNIC_IOREQ_ABTS_PENDING)
fnic_priv(sc)->state = old_ioreq_state;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
@@ -1717,7 +1726,7 @@ static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id)
};
FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host,
+ fnic->lport->host, fnic->fnic_num,
"fnic_rport_exch_reset called portid 0x%06x\n",
port_id);
@@ -1754,9 +1763,8 @@ void fnic_terminate_rport_io(struct fc_rport *rport)
return;
}
fnic = lport_priv(lport);
- FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host, "fnic_terminate_rport_io called"
- " wwpn 0x%llx, wwnn0x%llx, rport 0x%p, portid 0x%06x\n",
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
+ "wwpn 0x%llx, wwnn0x%llx, rport 0x%p, portid 0x%06x\n",
rport->port_name, rport->node_name, rport,
rport->port_id);
@@ -1861,8 +1869,9 @@ int fnic_abort_cmd(struct scsi_cmnd *sc)
else
atomic64_inc(&abts_stats->abort_issued_greater_than_60_sec);
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
- "CBD Opcode: %02x Abort issued time: %lu msec\n", sc->cmnd[0], abt_issued_time);
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
+ "CDB Opcode: 0x%02x Abort issued time: %lu msec\n",
+ sc->cmnd[0], abt_issued_time);
/*
* Command is still pending, need to abort it
* If the firmware completes the command after this point,
@@ -1951,8 +1960,8 @@ int fnic_abort_cmd(struct scsi_cmnd *sc)
if (!(fnic_priv(sc)->flags & (FNIC_IO_ABORTED | FNIC_IO_DONE))) {
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Issuing Host reset due to out of order IO\n");
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "Issuing host reset due to out of order IO\n");
ret = FAILED;
goto fnic_abort_cmd_end;
@@ -1999,7 +2008,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc)
(u64)sc->cmnd[4] << 8 | sc->cmnd[5]),
fnic_flags_and_state(sc));
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Returning from abort cmd type %x %s\n", task_req,
(ret == SUCCESS) ?
"SUCCESS" : "FAILED");
@@ -2037,7 +2046,7 @@ static inline int fnic_queue_dr_io_req(struct fnic *fnic,
free_wq_copy_descs(fnic, wq, hwq);
if (!vnic_wq_copy_desc_avail(wq)) {
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"queue_dr_io_req failure - no descriptors\n");
atomic64_inc(&misc_stats->devrst_cpwq_alloc_failures);
ret = -EAGAIN;
@@ -2104,7 +2113,7 @@ static bool fnic_pending_aborts_iter(struct scsi_cmnd *sc, void *data)
* Found IO that is still pending with firmware and
* belongs to the LUN that we are resetting
*/
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Found IO in %s on lun\n",
fnic_ioreq_state_to_str(fnic_priv(sc)->state));
@@ -2114,9 +2123,8 @@ static bool fnic_pending_aborts_iter(struct scsi_cmnd *sc, void *data)
}
if ((fnic_priv(sc)->flags & FNIC_DEVICE_RESET) &&
(!(fnic_priv(sc)->flags & FNIC_DEV_RST_ISSUED))) {
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
- "%s dev rst not pending sc 0x%p\n", __func__,
- sc);
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "dev rst not pending sc 0x%p\n", sc);
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
return true;
}
@@ -2138,8 +2146,8 @@ static bool fnic_pending_aborts_iter(struct scsi_cmnd *sc, void *data)
BUG_ON(io_req->abts_done);
if (fnic_priv(sc)->flags & FNIC_DEVICE_RESET) {
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
- "%s: dev rst sc 0x%p\n", __func__, sc);
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "dev rst sc 0x%p\n", sc);
}
fnic_priv(sc)->abts_status = FCPIO_INVALID_CODE;
@@ -2160,6 +2168,9 @@ static bool fnic_pending_aborts_iter(struct scsi_cmnd *sc, void *data)
fnic_priv(sc)->state = old_ioreq_state;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
iter_data->ret = FAILED;
+ FNIC_SCSI_DBG(KERN_ERR, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d abt_tag: 0x%lx Abort could not be queued\n",
+ hwq, abt_tag);
return false;
} else {
spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
@@ -2249,8 +2260,8 @@ static int fnic_clean_pending_aborts(struct fnic *fnic,
ret = 1;
clean_pending_aborts_end:
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
- "%s: exit status: %d\n", __func__, ret);
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "exit status: %d\n", ret);
return ret;
}
@@ -2291,9 +2302,10 @@ int fnic_device_reset(struct scsi_cmnd *sc)
atomic64_inc(&reset_stats->device_resets);
rport = starget_to_rport(scsi_target(sc->device));
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Device reset called FCID 0x%x, LUN 0x%llx sc 0x%p\n",
- rport->port_id, sc->device->lun, sc);
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
+ "fcid: 0x%x lun: 0x%llx hwq: %d mqtag: 0x%x flags: 0x%x Device reset\n",
+ rport->port_id, sc->device->lun, hwq, mqtag,
+ fnic_priv(sc)->flags);
if (lp->state != LPORT_ST_READY || !(lp->link_up))
goto fnic_device_reset_end;
@@ -2353,7 +2365,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
fnic_priv(sc)->lr_status = FCPIO_INVALID_CODE;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "TAG %x\n", mqtag);
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num, "TAG %x\n", mqtag);
/*
* issue the device reset, if enqueue failed, clean up the ioreq
@@ -2381,7 +2393,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
io_req = fnic_priv(sc)->io_req;
if (!io_req) {
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"io_req is null mqtag 0x%x sc 0x%p\n", mqtag, sc);
goto fnic_device_reset_end;
}
@@ -2395,7 +2407,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
*/
if (status == FCPIO_INVALID_CODE) {
atomic64_inc(&reset_stats->device_reset_timeouts);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Device reset timed out\n");
fnic_priv(sc)->flags |= FNIC_DEV_RST_TIMED_OUT;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
@@ -2423,7 +2435,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
fnic_priv(sc)->state = FNIC_IOREQ_ABTS_PENDING;
io_req->abts_done = &tm_done;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Abort and terminate issued on Device reset mqtag 0x%x sc 0x%p\n",
mqtag, sc);
break;
@@ -2450,7 +2462,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
if (status != FCPIO_SUCCESS) {
spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
FNIC_SCSI_DBG(KERN_DEBUG,
- fnic->lport->host,
+ fnic->lport->host, fnic->fnic_num,
"Device reset completed - failed\n");
io_req = fnic_priv(sc)->io_req;
goto fnic_device_reset_clean;
@@ -2466,7 +2478,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
if (fnic_clean_pending_aborts(fnic, sc, new_sc)) {
spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
io_req = fnic_priv(sc)->io_req;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Device reset failed"
" since could not abort all IOs\n");
goto fnic_device_reset_clean;
@@ -2507,7 +2519,7 @@ int fnic_device_reset(struct scsi_cmnd *sc)
mutex_unlock(&fnic->sgreset_mutex);
}
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"Returning from device reset %s\n",
(ret == SUCCESS) ?
"SUCCESS" : "FAILED");
@@ -2530,8 +2542,8 @@ int fnic_reset(struct Scsi_Host *shost)
fnic = lport_priv(lp);
reset_stats = &fnic->fnic_stats.reset_stats;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "fnic_reset called\n");
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "Issuing fnic reset\n");
atomic64_inc(&reset_stats->fnic_resets);
@@ -2541,10 +2553,9 @@ int fnic_reset(struct Scsi_Host *shost)
*/
ret = fc_lport_reset(lp);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "Returning from fnic reset %s\n",
- (ret == 0) ?
- "SUCCESS" : "FAILED");
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "Returning from fnic reset with: %s\n",
+ (ret == 0) ? "SUCCESS" : "FAILED");
if (ret == 0)
atomic64_inc(&reset_stats->fnic_reset_completions);
@@ -2577,7 +2588,7 @@ int fnic_host_reset(struct scsi_cmnd *sc)
fnic->internal_reset_inprogress = true;
} else {
spin_unlock_irqrestore(&fnic->fnic_lock, flags);
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"host reset in progress skipping another host reset\n");
return SUCCESS;
}
@@ -2652,7 +2663,7 @@ void fnic_scsi_abort_io(struct fc_lport *lp)
spin_lock_irqsave(&fnic->fnic_lock, flags);
fnic->remove_wait = NULL;
- FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
+ FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, fnic->fnic_num,
"fnic_scsi_abort_io %s\n",
(fnic->state == FNIC_IN_ETH_MODE) ?
"SUCCESS" : "FAILED");
@@ -2759,9 +2770,10 @@ static bool fnic_abts_pending_iter(struct scsi_cmnd *sc, void *data)
* Found IO that is still pending with firmware and
* belongs to the LUN that we are resetting
*/
- FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host,
- "Found IO in %s on lun\n",
- fnic_ioreq_state_to_str(fnic_priv(sc)->state));
+ FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, fnic->fnic_num,
+ "hwq: %d tag: 0x%x Found IO in state: %s on lun\n",
+ hwq, tag,
+ fnic_ioreq_state_to_str(fnic_priv(sc)->state));
cmd_state = fnic_priv(sc)->state;
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
if (cmd_state == FNIC_IOREQ_ABTS_PENDING)
--
2.31.1
Powered by blists - more mailing lists