diff mbox series

[v2,13/13] scsi: fnic: Improve logs and add support for multiqueue (MQ)

Message ID 20231027180302.418676-14-kartilak@cisco.com (mailing list archive)
State Superseded
Headers show
Series Introduce support for multiqueue (MQ) in fnic | expand

Commit Message

Karan Tilak Kumar (kartilak) Oct. 27, 2023, 6:03 p.m. UTC 
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

Hannes Reinecke Nov. 2, 2023, 7:59 a.m. UTC | #1 
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>
Hannes Reinecke Nov. 2, 2023, 8:14 a.m. UTC | #2 
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
Karan Tilak Kumar (kartilak) Nov. 6, 2023, 8:30 p.m. UTC | #3 
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
Karan Tilak Kumar (kartilak) Nov. 6, 2023, 8:44 p.m. UTC | #4 
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
Hannes Reinecke Nov. 7, 2023, 7:27 a.m. UTC | #5 
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
Karan Tilak Kumar (kartilak) Nov. 7, 2023, 6:41 p.m. UTC | #6 
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
diff mbox series

Patch

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_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)