[v2,13/13] scsi: fnic: Improve logs and add support for multiqueue (MQ)
Commit Message
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@cisco.com>
Reviewed-by: Arulprabhu Ponnusamy <arulponn@cisco.com>
Tested-by: Karan Tilak Kumar <kartilak@cisco.com>
Signed-off-by: Karan Tilak Kumar <kartilak@cisco.com>
---
drivers/scsi/fnic/fnic.h | 2 +-
drivers/scsi/fnic/fnic_scsi.c | 127 ++++++++++++++++++++--------------
2 files changed, 77 insertions(+), 52 deletions(-)
Comments
On 10/27/23 20:03, Karan Tilak Kumar wrote:
> 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@cisco.com>
> Reviewed-by: Arulprabhu Ponnusamy <arulponn@cisco.com>
> Tested-by: Karan Tilak Kumar <kartilak@cisco.com>
> Signed-off-by: Karan Tilak Kumar <kartilak@cisco.com>
> ---
> drivers/scsi/fnic/fnic.h | 2 +-
> drivers/scsi/fnic/fnic_scsi.c | 127 ++++++++++++++++++++--------------
> 2 files changed, 77 insertions(+), 52 deletions(-)
>
> diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h
> index 87dab09a426d..0f1581c1fb4a 100644
> --- a/drivers/scsi/fnic/fnic.h
> +++ b/drivers/scsi/fnic/fnic.h
> @@ -27,7 +27,7 @@
>
> #define DRV_NAME "fnic"
> #define DRV_DESCRIPTION "Cisco FCoE HBA Driver"
> -#define DRV_VERSION "1.6.0.56"
> +#define DRV_VERSION "1.6.0.58"
> #define PFX DRV_NAME ": "
> #define DFX DRV_NAME "%d: "
>
Please move this change to the last patch.
And I would wager that this change is more intrusive than a simple
patch, so an update to 1.7 or even 2.0 is warranted.
Otherwise:
Reviewed-by: Hannes Reinecke <hare@suse.de>
On 10/27/23 20:03, Karan Tilak Kumar wrote:
> 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@cisco.com>
> Reviewed-by: Arulprabhu Ponnusamy <arulponn@cisco.com>
> Tested-by: Karan Tilak Kumar <kartilak@cisco.com>
> Signed-off-by: Karan Tilak Kumar <kartilak@cisco.com>
> ---
> drivers/scsi/fnic/fnic.h | 2 +-
> drivers/scsi/fnic/fnic_scsi.c | 127 ++++++++++++++++++++--------------
> 2 files changed, 77 insertions(+), 52 deletions(-)
>
> diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h
> index 87dab09a426d..0f1581c1fb4a 100644
> --- a/drivers/scsi/fnic/fnic.h
> +++ b/drivers/scsi/fnic/fnic.h
> @@ -27,7 +27,7 @@
>
> #define DRV_NAME "fnic"
> #define DRV_DESCRIPTION "Cisco FCoE HBA Driver"
> -#define DRV_VERSION "1.6.0.56"
> +#define DRV_VERSION "1.6.0.58"
> #define PFX DRV_NAME ": "
> #define DFX DRV_NAME "%d: "
>
> diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c
> index fdc4d73ba63c..e6dccb752f7e 100644
> --- a/drivers/scsi/fnic/fnic_scsi.c
> +++ b/drivers/scsi/fnic/fnic_scsi.c
> @@ -211,12 +211,14 @@ 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<%d>: %s: %d: Issued fw reset\n",
> + fnic->fnic_num, __func__, __LINE__);
> } 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<%d>: %s: %d: Failed to issue fw reset\n",
> + fnic->fnic_num, __func__, __LINE__);
> }
>
> return ret;
> @@ -265,9 +267,9 @@ int fnic_flogi_reg_handler(struct fnic *fnic, u32 fc_id)
> } 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<%d>: %s: %d: FLOGI reg issued fcid 0x%x map %d dest 0x%p\n",
> + fnic->fnic_num, __func__, __LINE__, fc_id, fnic->ctlr.map_dest, gw_mac);
> }
>
> atomic64_inc(&fnic->fnic_stats.fw_stats.active_fw_reqs);
> @@ -644,15 +646,16 @@ 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<%d>: %s: %d: reset cmpl success\n",
> + fnic->fnic_num, __func__, __LINE__);
> /* 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<%d>: %s: %d: reset failed with header status: %s\n",
> + fnic->fnic_num, __func__, __LINE__,
> + fnic_fcpio_status_to_str(hdr_status));
>
> /*
> * Unable to change to eth mode, cannot send out flogi
> @@ -665,10 +668,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<%d>: %s: %d: Unexpected state while processing reset completion: %s\n",
> + fnic->fnic_num, __func__, __LINE__, fnic_state_to_str(fnic->state));
> atomic64_inc(&reset_stats->fw_reset_failures);
> ret = -1;
> }
> @@ -1177,9 +1179,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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Abt/term completion received\n",
> + fnic->fnic_num, __func__, __LINE__, 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;
> @@ -1188,6 +1191,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,
> + "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x Abort header status: %s\n",
> + fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag,
> + fnic_fcpio_status_to_str(hdr_status));
> switch (hdr_status) {
> case FCPIO_SUCCESS:
> break;
> @@ -1247,9 +1254,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,
> + "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x Waking up abort thread\n",
> + fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag);
> } else {
> FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
> - "abts cmpl, completing IO\n");
> + "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Completing IO\n",
> + fnic->fnic_num, __func__, __LINE__, 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;
> @@ -1277,6 +1289,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,
> + "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x DR hst: %s\n",
> + fnic->fnic_num, __func__, __LINE__, 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);
> @@ -1286,10 +1302,9 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
> 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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Terminate pending\n",
> + fnic->fnic_num, __func__, __LINE__, hwq, mqtag,
> + tag, fnic_fcpio_status_to_str(hdr_status));
> return;
> }
> if (fnic_priv(sc)->flags & FNIC_DEV_RST_TIMED_OUT) {
> @@ -1308,18 +1323,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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s DR completion received\n",
> + fnic->fnic_num, __func__, __LINE__, 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);
> }
>
> @@ -1470,9 +1485,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<%d>: %s: %d: mqtag:0x%x tag: 0x%x sc:0x%p duration = %lu DID_TRANSPORT_DISRUPTED\n",
> + fnic->fnic_num, __func__, __LINE__, mqtag, tag, sc, (jiffies - start_time));
>
> if (atomic64_read(&fnic->io_cmpl_skip))
> atomic64_dec(&fnic->io_cmpl_skip);
> @@ -1641,9 +1656,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<%d>: %s: %d: hwq: %d abt_tag: 0x%x flags: 0x%x Device reset is not pending\n",
> + fnic->fnic_num, __func__, __LINE__, hwq, abt_tag, fnic_priv(sc)->flags);
> spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
> return true;
> }
> @@ -1699,6 +1714,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<%d>: %s: %d: hwq: %d abt_tag: 0x%x flags: 0x%x Queuing abort failed\n",
> + fnic->fnic_num, __func__, __LINE__, 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);
> @@ -1869,8 +1887,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<%d>: %s: CDB Opcode: 0x%02x Abort issued time: %lu msec\n",
> + fnic->fnic_num, __func__, sc->cmnd[0], abt_issued_time);
> /*
> * Command is still pending, need to abort it
> * If the firmware completes the command after this point,
> @@ -1959,8 +1978,9 @@ 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<%d>: %s: Issuing host reset due to out of order IO\n",
> + fnic->fnic_num, __func__);
>
> ret = FAILED;
> goto fnic_abort_cmd_end;
> @@ -2167,6 +2187,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<%d>: %s: %d: hwq: %d abt_tag: 0x%lx Abort could not be queued\n",
> + fnic->fnic_num, __func__, __LINE__, hwq, abt_tag);
> return false;
> } else {
> spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
> @@ -2300,8 +2323,9 @@ int fnic_device_reset(struct scsi_cmnd *sc)
>
> 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<%d>: %s: %d: fcid: 0x%x lun: 0x%llx hwq: %d mqtag: 0x%x flags: 0x%x Device reset\n",
> + fnic->fnic_num, __func__, __LINE__, 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;
> @@ -2536,8 +2560,9 @@ 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<%d>: %s: %d: Issuing fnic reset\n",
> + fnic->fnic_num, __func__, __LINE__);
>
> atomic64_inc(&reset_stats->fnic_resets);
>
> @@ -2547,10 +2572,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<%d>: %s: %d: Returning from fnic reset with: %s\n",
> + fnic->fnic_num, __func__, __LINE__, (ret == 0) ? "SUCCESS" : "FAILED");
>
> if (ret == 0)
> atomic64_inc(&reset_stats->fnic_reset_completio to a > @@ -2766,8 +2790,9 @@ static bool fnic_abts_pending_iter(struct
scsi_cmnd *sc, void *data)
> * 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<%d>: %s: %d: hwq: %d tag: 0x%x Found IO in state: %s on lun\n",
> + fnic->fnic_num, __func__, __LINE__, 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)
See my comments to the previous patch. Please update FNIC_SCSI_DBG() to
accept an 'fnic' parameter instead of 'fnic->lport->host', and generate
the 'fnic<%d>' here in the macro.
Cheers,
Hannes
On Thursday, November 2, 2023 1:14 AM, Hannes Reinecke <hare@suse.de> wrote:
>
> See my comments to the previous patch. Please update FNIC_SCSI_DBG() to accept an 'fnic' parameter instead of 'fnic->lport->host', and generate the 'fnic<%d>' here in the macro.
>
Sure, I'll make suitable changes in v3.
Regards,
Karan
On Thursday, November 2, 2023 12:59 AM, Hannes Reinecke <hare@suse.de> wrote:
> Please move this change to the last patch.
> And I would wager that this change is more intrusive than a simple patch, so an update to 1.7 or even 2.0 is warranted.
>
The version change is in the last patch of the patchset.
Do you mean that I need to make a separate patch to increment the version number?
In v3, I'll update it to 1.7.0.0.
Regards,
Karan
On 11/6/23 21:44, Karan Tilak Kumar (kartilak) wrote:
> On Thursday, November 2, 2023 12:59 AM, Hannes Reinecke <hare@suse.de> wrote:
>> Please move this change to the last patch.
>> And I would wager that this change is more intrusive than a simple patch, so an update to 1.7 or even 2.0 is warranted.
>>
>
> The version change is in the last patch of the patchset.
> Do you mean that I need to make a separate patch to increment the version number?
> In v3, I'll update it to 1.7.0.0.
>
Yes, please. And make this the last patch of the patch series.
Cheers,
Hannes
On Monday, November 6, 2023 11:27 PM, Hannes Reinecke <hare@suse.de> wrote:
>
> On 11/6/23 21:44, Karan Tilak Kumar (kartilak) wrote:
> > On Thursday, November 2, 2023 12:59 AM, Hannes Reinecke <hare@suse.de> wrote:
> >> Please move this change to the last patch.
> >> And I would wager that this change is more intrusive than a simple patch, so an update to 1.7 or even 2.0 is warranted.
> >>
> >
> > The version change is in the last patch of the patchset.
> > Do you mean that I need to make a separate patch to increment the version number?
> > In v3, I'll update it to 1.7.0.0.
> >
> Yes, please. And make this the last patch of the patch series.
Sure, will do. I'll make this change in v3.
Regards,
Karan
@@ -27,7 +27,7 @@
#define DRV_NAME "fnic"
#define DRV_DESCRIPTION "Cisco FCoE HBA Driver"
-#define DRV_VERSION "1.6.0.56"
+#define DRV_VERSION "1.6.0.58"
#define PFX DRV_NAME ": "
#define DFX DRV_NAME "%d: "
@@ -211,12 +211,14 @@ 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<%d>: %s: %d: Issued fw reset\n",
+ fnic->fnic_num, __func__, __LINE__);
} 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<%d>: %s: %d: Failed to issue fw reset\n",
+ fnic->fnic_num, __func__, __LINE__);
}
return ret;
@@ -265,9 +267,9 @@ int fnic_flogi_reg_handler(struct fnic *fnic, u32 fc_id)
} 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<%d>: %s: %d: FLOGI reg issued fcid 0x%x map %d dest 0x%p\n",
+ fnic->fnic_num, __func__, __LINE__, fc_id, fnic->ctlr.map_dest, gw_mac);
}
atomic64_inc(&fnic->fnic_stats.fw_stats.active_fw_reqs);
@@ -644,15 +646,16 @@ 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<%d>: %s: %d: reset cmpl success\n",
+ fnic->fnic_num, __func__, __LINE__);
/* 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<%d>: %s: %d: reset failed with header status: %s\n",
+ fnic->fnic_num, __func__, __LINE__,
+ fnic_fcpio_status_to_str(hdr_status));
/*
* Unable to change to eth mode, cannot send out flogi
@@ -665,10 +668,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<%d>: %s: %d: Unexpected state while processing reset completion: %s\n",
+ fnic->fnic_num, __func__, __LINE__, fnic_state_to_str(fnic->state));
atomic64_inc(&reset_stats->fw_reset_failures);
ret = -1;
}
@@ -1177,9 +1179,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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Abt/term completion received\n",
+ fnic->fnic_num, __func__, __LINE__, 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;
@@ -1188,6 +1191,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,
+ "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x Abort header status: %s\n",
+ fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag,
+ fnic_fcpio_status_to_str(hdr_status));
switch (hdr_status) {
case FCPIO_SUCCESS:
break;
@@ -1247,9 +1254,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,
+ "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x Waking up abort thread\n",
+ fnic->fnic_num, __func__, __LINE__, hwq, mqtag, tag);
} else {
FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host,
- "abts cmpl, completing IO\n");
+ "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Completing IO\n",
+ fnic->fnic_num, __func__, __LINE__, 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;
@@ -1277,6 +1289,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,
+ "fnic<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x DR hst: %s\n",
+ fnic->fnic_num, __func__, __LINE__, 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);
@@ -1286,10 +1302,9 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, unsigned int cq_inde
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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s Terminate pending\n",
+ fnic->fnic_num, __func__, __LINE__, hwq, mqtag,
+ tag, fnic_fcpio_status_to_str(hdr_status));
return;
}
if (fnic_priv(sc)->flags & FNIC_DEV_RST_TIMED_OUT) {
@@ -1308,18 +1323,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<%d>: %s: %d: hwq: %d mqtag: 0x%x tag: 0x%x hst: %s DR completion received\n",
+ fnic->fnic_num, __func__, __LINE__, 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);
}
@@ -1470,9 +1485,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<%d>: %s: %d: mqtag:0x%x tag: 0x%x sc:0x%p duration = %lu DID_TRANSPORT_DISRUPTED\n",
+ fnic->fnic_num, __func__, __LINE__, mqtag, tag, sc, (jiffies - start_time));
if (atomic64_read(&fnic->io_cmpl_skip))
atomic64_dec(&fnic->io_cmpl_skip);
@@ -1641,9 +1656,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<%d>: %s: %d: hwq: %d abt_tag: 0x%x flags: 0x%x Device reset is not pending\n",
+ fnic->fnic_num, __func__, __LINE__, hwq, abt_tag, fnic_priv(sc)->flags);
spin_unlock_irqrestore(&fnic->wq_copy_lock[hwq], flags);
return true;
}
@@ -1699,6 +1714,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<%d>: %s: %d: hwq: %d abt_tag: 0x%x flags: 0x%x Queuing abort failed\n",
+ fnic->fnic_num, __func__, __LINE__, 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);
@@ -1869,8 +1887,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<%d>: %s: CDB Opcode: 0x%02x Abort issued time: %lu msec\n",
+ fnic->fnic_num, __func__, sc->cmnd[0], abt_issued_time);
/*
* Command is still pending, need to abort it
* If the firmware completes the command after this point,
@@ -1959,8 +1978,9 @@ 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<%d>: %s: Issuing host reset due to out of order IO\n",
+ fnic->fnic_num, __func__);
ret = FAILED;
goto fnic_abort_cmd_end;
@@ -2167,6 +2187,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<%d>: %s: %d: hwq: %d abt_tag: 0x%lx Abort could not be queued\n",
+ fnic->fnic_num, __func__, __LINE__, hwq, abt_tag);
return false;
} else {
spin_lock_irqsave(&fnic->wq_copy_lock[hwq], flags);
@@ -2300,8 +2323,9 @@ int fnic_device_reset(struct scsi_cmnd *sc)
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<%d>: %s: %d: fcid: 0x%x lun: 0x%llx hwq: %d mqtag: 0x%x flags: 0x%x Device reset\n",
+ fnic->fnic_num, __func__, __LINE__, 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;
@@ -2536,8 +2560,9 @@ 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<%d>: %s: %d: Issuing fnic reset\n",
+ fnic->fnic_num, __func__, __LINE__);
atomic64_inc(&reset_stats->fnic_resets);
@@ -2547,10 +2572,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<%d>: %s: %d: Returning from fnic reset with: %s\n",
+ fnic->fnic_num, __func__, __LINE__, (ret == 0) ? "SUCCESS" : "FAILED");
if (ret == 0)
atomic64_inc(&reset_stats->fnic_reset_completions);
@@ -2766,8 +2790,9 @@ static bool fnic_abts_pending_iter(struct scsi_cmnd *sc, void *data)
* 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<%d>: %s: %d: hwq: %d tag: 0x%x Found IO in state: %s on lun\n",
+ fnic->fnic_num, __func__, __LINE__, 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)