diff mbox series

[1/8] mpt3sas: Sync time stamp periodically between Driver and FW

Message ID 20201124035019.27975-2-suganath-prabu.subramani@broadcom.com (mailing list archive)
State Superseded
Headers show
Series mpt3sas: Features to enhance driver debugging. | expand

Commit Message

Suganath Prabu S Nov. 24, 2020, 3:50 a.m. UTC 
Issue Description:
In current Driver/FW, the controller timestamp gets updated
with host time during driver load time or when a controller
reset is issued. i.e. when host issues the IOCInit request
message to the HBA FW. This IOCInit message has a field named
'TimeStamp' using which the host updates the controller
timestamp. Over a period, sometimes we may observe controller
time drifting away from host and it is difficult to co-relate
host logs with controller logs with respect to time.
And every time driver cannot issue the IOCInit request message
just for updating the controller timestamp.

Implementation:
Instead of IOCInit, driver sends IO_UNIT_CONTROL Request to
sync time stamp periodically with controller. Timestamp
synchronization interval is specified in 'TimeSyncInterval'
field of Manufacturing Page11 by controller.
TimeSyncInterval - 8 bits
        bits  0-6: Time stamp Synchronization interval value
        bit     7: Time stamp Synchronization interval unit,
                (if this bit is one then Timestamp Synchronization
                interval value is specified in terms of hours else
                Timestamp Synchronization interval value is
                specified in terms of minutes).

Driver sends this IO_UNIT_CONTROL Request message from
watchdog thread (which gets invoked every one second).
Driver keeps tracks of timer using ioc's timestamp_update_count
field. This field value gets incremented whenever the watchdog
thread gets invoked. And whenever this field value is greater
than or equals to the Time stamp Synchronization interval value
then driver sends the IO_UNIT_CONTROL Request message to
controller to update the time stamp and then it resets the
timestamp_update_count field to zero.

Syncing Driver and FW timestamp periodically makes
correlating the FW logs and OS events easier.

Signed-off-by: Suganath Prabu S <suganath-prabu.subramani@broadcom.com>
---
 drivers/scsi/mpt3sas/mpt3sas_base.c | 93 ++++++++++++++++++++++++++++-
 drivers/scsi/mpt3sas/mpt3sas_base.h | 14 ++++-
 2 files changed, 104 insertions(+), 3 deletions(-)

Comments

kernel test robot Nov. 24, 2020, 7:46 a.m. UTC | #1 
Hi Suganath,

I love your patch! Perhaps something to improve:

[auto build test WARNING on scsi/for-next]
[also build test WARNING on mkp-scsi/for-next v5.10-rc5 next-20201123]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url:    https://github.com/0day-ci/linux/commits/Suganath-Prabu-S/mpt3sas-Features-to-enhance-driver-debugging/20201124-115842
base:   https://git.kernel.org/pub/scm/linux/kernel/git/jejb/scsi.git for-next
config: i386-randconfig-s001-20201124 (attached as .config)
compiler: gcc-9 (Debian 9.3.0-15) 9.3.0
reproduce:
        # apt-get install sparse
        # sparse version: v0.6.3-151-g540c2c4b-dirty
        # https://github.com/0day-ci/linux/commit/25de902f6dde291c7e0266b943d68ff8ed4d683b
        git remote add linux-review https://github.com/0day-ci/linux
        git fetch --no-tags linux-review Suganath-Prabu-S/mpt3sas-Features-to-enhance-driver-debugging/20201124-115842
        git checkout 25de902f6dde291c7e0266b943d68ff8ed4d683b
        # save the attached .config to linux build tree
        make W=1 C=1 CF='-fdiagnostic-prefix -D__CHECK_ENDIAN__' ARCH=i386 

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <lkp@intel.com>


"sparse warnings: (new ones prefixed by >>)"
>> drivers/scsi/mpt3sas/mpt3sas_base.c:633:19: sparse: sparse: incorrect type in assignment (different base types) @@     expected unsigned long long [usertype] TimeStamp @@     got restricted __le64 [usertype] @@
>> drivers/scsi/mpt3sas/mpt3sas_base.c:633:19: sparse:     expected unsigned long long [usertype] TimeStamp
   drivers/scsi/mpt3sas/mpt3sas_base.c:633:19: sparse:     got restricted __le64 [usertype]
>> drivers/scsi/mpt3sas/mpt3sas_base.c:634:32: sparse: sparse: incorrect type in assignment (different base types) @@     expected restricted __le32 [usertype] Reserved7 @@     got unsigned int [usertype] @@
>> drivers/scsi/mpt3sas/mpt3sas_base.c:634:32: sparse:     expected restricted __le32 [usertype] Reserved7
   drivers/scsi/mpt3sas/mpt3sas_base.c:634:32: sparse:     got unsigned int [usertype]
>> drivers/scsi/mpt3sas/mpt3sas_base.c:635:40: sparse: sparse: incorrect type in assignment (different base types) @@     expected restricted __le32 [usertype] IOCParameterValue @@     got unsigned int [usertype] @@
>> drivers/scsi/mpt3sas/mpt3sas_base.c:635:40: sparse:     expected restricted __le32 [usertype] IOCParameterValue
   drivers/scsi/mpt3sas/mpt3sas_base.c:635:40: sparse:     got unsigned int [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:1704:64: sparse: sparse: incorrect type in argument 2 (different address spaces) @@     expected void volatile [noderef] __iomem *addr @@     got unsigned long long [usertype] * @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:1704:64: sparse:     expected void volatile [noderef] __iomem *addr
   drivers/scsi/mpt3sas/mpt3sas_base.c:1704:64: sparse:     got unsigned long long [usertype] *
   drivers/scsi/mpt3sas/mpt3sas_base.c:1758:52: sparse: sparse: incorrect type in argument 2 (different address spaces) @@     expected void volatile [noderef] __iomem *addr @@     got unsigned long long [usertype] * @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:1758:52: sparse:     expected void volatile [noderef] __iomem *addr
   drivers/scsi/mpt3sas/mpt3sas_base.c:1758:52: sparse:     got unsigned long long [usertype] *
   drivers/scsi/mpt3sas/mpt3sas_base.c:4105:16: sparse: sparse: incorrect type in argument 1 (different base types) @@     expected unsigned int val @@     got restricted __le32 [usertype] @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:4105:16: sparse:     expected unsigned int val
   drivers/scsi/mpt3sas/mpt3sas_base.c:4105:16: sparse:     got restricted __le32 [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:4127:16: sparse: sparse: incorrect type in argument 1 (different base types) @@     expected unsigned int val @@     got restricted __le32 [usertype] @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:4127:16: sparse:     expected unsigned int val
   drivers/scsi/mpt3sas/mpt3sas_base.c:4127:16: sparse:     got restricted __le32 [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:4150:16: sparse: sparse: incorrect type in argument 1 (different base types) @@     expected unsigned int val @@     got restricted __le32 [usertype] @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:4150:16: sparse:     expected unsigned int val
   drivers/scsi/mpt3sas/mpt3sas_base.c:4150:16: sparse:     got restricted __le32 [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:4171:16: sparse: sparse: incorrect type in argument 1 (different base types) @@     expected unsigned int val @@     got restricted __le32 [usertype] @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:4171:16: sparse:     expected unsigned int val
   drivers/scsi/mpt3sas/mpt3sas_base.c:4171:16: sparse:     got restricted __le32 [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:6035:24: sparse: sparse: incorrect type in argument 1 (different base types) @@     expected unsigned int val @@     got restricted __le32 [usertype] @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:6035:24: sparse:     expected unsigned int val
   drivers/scsi/mpt3sas/mpt3sas_base.c:6035:24: sparse:     got restricted __le32 [usertype]
   drivers/scsi/mpt3sas/mpt3sas_base.c:6054:20: sparse: sparse: cast to restricted __le16
   drivers/scsi/mpt3sas/mpt3sas_base.c:6062:20: sparse: sparse: cast to restricted __le16
   drivers/scsi/mpt3sas/mpt3sas_base.c:6075:36: sparse: sparse: cast to restricted __le16
   drivers/scsi/mpt3sas/mpt3sas_base.c:7213:55: sparse: sparse: incorrect type in argument 2 (different address spaces) @@     expected void volatile [noderef] __iomem *addr @@     got unsigned long long [usertype] * @@
   drivers/scsi/mpt3sas/mpt3sas_base.c:7213:55: sparse:     expected void volatile [noderef] __iomem *addr
   drivers/scsi/mpt3sas/mpt3sas_base.c:7213:55: sparse:     got unsigned long long [usertype] *

vim +633 drivers/scsi/mpt3sas/mpt3sas_base.c

   598	
   599	/**
   600	 * _base_sync_drv_fw_timestamp - Sync Drive-Fw TimeStamp.
   601	 * @ioc: Per Adapter Object
   602	 *
   603	 * Return nothing.
   604	 */
   605	static void _base_sync_drv_fw_timestamp(struct MPT3SAS_ADAPTER *ioc)
   606	{
   607		Mpi26IoUnitControlRequest_t *mpi_request;
   608		Mpi26IoUnitControlReply_t *mpi_reply;
   609		u16 smid;
   610		ktime_t current_time;
   611		u64 TimeStamp = 0;
   612		u8 issue_reset = 0;
   613	
   614		mutex_lock(&ioc->scsih_cmds.mutex);
   615		if (ioc->scsih_cmds.status != MPT3_CMD_NOT_USED) {
   616			ioc_err(ioc, "scsih_cmd in use %s\n", __func__);
   617			goto out;
   618		}
   619		ioc->scsih_cmds.status = MPT3_CMD_PENDING;
   620		smid = mpt3sas_base_get_smid(ioc, ioc->scsih_cb_idx);
   621		if (!smid) {
   622			ioc_err(ioc, "Failed obtaining a smid %s\n", __func__);
   623			ioc->scsih_cmds.status = MPT3_CMD_NOT_USED;
   624			goto out;
   625		}
   626		mpi_request = mpt3sas_base_get_msg_frame(ioc, smid);
   627		ioc->scsih_cmds.smid = smid;
   628		memset(mpi_request, 0, sizeof(Mpi26IoUnitControlRequest_t));
   629		mpi_request->Function = MPI2_FUNCTION_IO_UNIT_CONTROL;
   630		mpi_request->Operation = MPI26_CTRL_OP_SET_IOC_PARAMETER;
   631		mpi_request->IOCParameter = MPI26_SET_IOC_PARAMETER_SYNC_TIMESTAMP;
   632		current_time = ktime_get_real();
 > 633		TimeStamp = cpu_to_le64(ktime_to_ms(current_time));
 > 634		mpi_request->Reserved7 = (u32) (TimeStamp & 0xFFFFFFFF);
 > 635		mpi_request->IOCParameterValue = (u32) (TimeStamp >> 32);
   636		init_completion(&ioc->scsih_cmds.done);
   637		ioc->put_smid_default(ioc, smid);
   638		dinitprintk(ioc, ioc_info(ioc,
   639		    "Io Unit Control Sync TimeStamp (sending), @time %lld ms\n",
   640		    TimeStamp));
   641		wait_for_completion_timeout(&ioc->scsih_cmds.done,
   642			MPT3SAS_TIMESYNC_TIMEOUT_SECONDS*HZ);
   643		if (!(ioc->scsih_cmds.status & MPT3_CMD_COMPLETE)) {
   644			mpt3sas_check_cmd_timeout(ioc,
   645			    ioc->scsih_cmds.status, mpi_request,
   646			    sizeof(Mpi2SasIoUnitControlRequest_t)/4, issue_reset);
   647			goto issue_host_reset;
   648		}
   649		if (ioc->scsih_cmds.status & MPT3_CMD_REPLY_VALID) {
   650			mpi_reply = ioc->scsih_cmds.reply;
   651			dinitprintk(ioc, ioc_info(ioc,
   652			    "Io Unit Control sync timestamp (complete): ioc_status(0x%04x), loginfo(0x%08x)\n",
   653			    le16_to_cpu(mpi_reply->IOCStatus),
   654			    le32_to_cpu(mpi_reply->IOCLogInfo)));
   655		}
   656	issue_host_reset:
   657		if (issue_reset)
   658			mpt3sas_base_hard_reset_handler(ioc, FORCE_BIG_HAMMER);
   659		ioc->scsih_cmds.status = MPT3_CMD_NOT_USED;
   660	out:
   661		mutex_unlock(&ioc->scsih_cmds.mutex);
   662	}
   663	

---
0-DAY CI Kernel Test Service, Intel Corporation
https://lists.01.org/hyperkitty/list/kbuild-all@lists.01.org
diff mbox series

Patch

diff --git a/drivers/scsi/mpt3sas/mpt3sas_base.c b/drivers/scsi/mpt3sas/mpt3sas_base.c
index 93230cd..18d5c3c 100644
--- a/drivers/scsi/mpt3sas/mpt3sas_base.c
+++ b/drivers/scsi/mpt3sas/mpt3sas_base.c
@@ -596,6 +596,71 @@  static int mpt3sas_remove_dead_ioc_func(void *arg)
 	return 0;
 }
 
+/**
+ * _base_sync_drv_fw_timestamp - Sync Drive-Fw TimeStamp.
+ * @ioc: Per Adapter Object
+ *
+ * Return nothing.
+ */
+static void _base_sync_drv_fw_timestamp(struct MPT3SAS_ADAPTER *ioc)
+{
+	Mpi26IoUnitControlRequest_t *mpi_request;
+	Mpi26IoUnitControlReply_t *mpi_reply;
+	u16 smid;
+	ktime_t current_time;
+	u64 TimeStamp = 0;
+	u8 issue_reset = 0;
+
+	mutex_lock(&ioc->scsih_cmds.mutex);
+	if (ioc->scsih_cmds.status != MPT3_CMD_NOT_USED) {
+		ioc_err(ioc, "scsih_cmd in use %s\n", __func__);
+		goto out;
+	}
+	ioc->scsih_cmds.status = MPT3_CMD_PENDING;
+	smid = mpt3sas_base_get_smid(ioc, ioc->scsih_cb_idx);
+	if (!smid) {
+		ioc_err(ioc, "Failed obtaining a smid %s\n", __func__);
+		ioc->scsih_cmds.status = MPT3_CMD_NOT_USED;
+		goto out;
+	}
+	mpi_request = mpt3sas_base_get_msg_frame(ioc, smid);
+	ioc->scsih_cmds.smid = smid;
+	memset(mpi_request, 0, sizeof(Mpi26IoUnitControlRequest_t));
+	mpi_request->Function = MPI2_FUNCTION_IO_UNIT_CONTROL;
+	mpi_request->Operation = MPI26_CTRL_OP_SET_IOC_PARAMETER;
+	mpi_request->IOCParameter = MPI26_SET_IOC_PARAMETER_SYNC_TIMESTAMP;
+	current_time = ktime_get_real();
+	TimeStamp = cpu_to_le64(ktime_to_ms(current_time));
+	mpi_request->Reserved7 = (u32) (TimeStamp & 0xFFFFFFFF);
+	mpi_request->IOCParameterValue = (u32) (TimeStamp >> 32);
+	init_completion(&ioc->scsih_cmds.done);
+	ioc->put_smid_default(ioc, smid);
+	dinitprintk(ioc, ioc_info(ioc,
+	    "Io Unit Control Sync TimeStamp (sending), @time %lld ms\n",
+	    TimeStamp));
+	wait_for_completion_timeout(&ioc->scsih_cmds.done,
+		MPT3SAS_TIMESYNC_TIMEOUT_SECONDS*HZ);
+	if (!(ioc->scsih_cmds.status & MPT3_CMD_COMPLETE)) {
+		mpt3sas_check_cmd_timeout(ioc,
+		    ioc->scsih_cmds.status, mpi_request,
+		    sizeof(Mpi2SasIoUnitControlRequest_t)/4, issue_reset);
+		goto issue_host_reset;
+	}
+	if (ioc->scsih_cmds.status & MPT3_CMD_REPLY_VALID) {
+		mpi_reply = ioc->scsih_cmds.reply;
+		dinitprintk(ioc, ioc_info(ioc,
+		    "Io Unit Control sync timestamp (complete): ioc_status(0x%04x), loginfo(0x%08x)\n",
+		    le16_to_cpu(mpi_reply->IOCStatus),
+		    le32_to_cpu(mpi_reply->IOCLogInfo)));
+	}
+issue_host_reset:
+	if (issue_reset)
+		mpt3sas_base_hard_reset_handler(ioc, FORCE_BIG_HAMMER);
+	ioc->scsih_cmds.status = MPT3_CMD_NOT_USED;
+out:
+	mutex_unlock(&ioc->scsih_cmds.mutex);
+}
+
 /**
  * _base_fault_reset_work - workq handling ioc fault conditions
  * @work: input argument, used to derive ioc
@@ -720,7 +785,11 @@  _base_fault_reset_work(struct work_struct *work)
 			return; /* don't rearm timer */
 	}
 	ioc->ioc_coredump_loop = 0;
-
+	if (ioc->time_sync_interval &&
+	    ++ioc->timestamp_update_count >= ioc->time_sync_interval) {
+		ioc->timestamp_update_count = 0;
+		_base_sync_drv_fw_timestamp(ioc);
+	}
 	spin_lock_irqsave(&ioc->ioc_reset_in_progress_lock, flags);
  rearm_timer:
 	if (ioc->fault_reset_work_q)
@@ -744,6 +813,7 @@  mpt3sas_base_start_watchdog(struct MPT3SAS_ADAPTER *ioc)
 	if (ioc->fault_reset_work_q)
 		return;
 
+	ioc->timestamp_update_count = 0;
 	/* initialize fault polling */
 
 	INIT_DELAYED_WORK(&ioc->fault_reset_work, _base_fault_reset_work);
@@ -4754,7 +4824,24 @@  _base_static_config_pages(struct MPT3SAS_ADAPTER *ioc)
 		else
 			ioc->nvme_abort_timeout = ioc->manu_pg11.NVMeAbortTO;
 	}
-
+	ioc->time_sync_interval =
+	    ioc->manu_pg11.TimeSyncInterval & MPT3SAS_TIMESYNC_MASK;
+	if (ioc->time_sync_interval) {
+		if (ioc->manu_pg11.TimeSyncInterval & MPT3SAS_TIMESYNC_UNIT_MASK)
+			ioc->time_sync_interval =
+			    ioc->time_sync_interval * SECONDS_PER_HOUR;
+		else
+			ioc->time_sync_interval =
+			    ioc->time_sync_interval * SECONDS_PER_MIN;
+		dinitprintk(ioc, ioc_info(ioc,
+		    "Driver-FW TimeSync interval is %d seconds. ManuPg11 TimeSync Unit is in %s\n",
+		    ioc->time_sync_interval, (ioc->manu_pg11.TimeSyncInterval &
+		    MPT3SAS_TIMESYNC_UNIT_MASK) ? "Hour" : "Minute"));
+	} else {
+		if (ioc->is_gen35_ioc)
+			ioc_warn(ioc,
+			    "TimeSync Interval in Manuf page-11 is not enabled. Periodic Time-Sync will be disabled\n");
+	}
 	mpt3sas_config_get_bios_pg2(ioc, &mpi_reply, &ioc->bios_pg2);
 	mpt3sas_config_get_bios_pg3(ioc, &mpi_reply, &ioc->bios_pg3);
 	mpt3sas_config_get_ioc_pg8(ioc, &mpi_reply, &ioc->ioc_pg8);
@@ -6466,6 +6553,8 @@  _base_send_ioc_init(struct MPT3SAS_ADAPTER *ioc)
 		r = -EIO;
 	}
 
+	/* Reset TimeSync Counter*/
+	ioc->timestamp_update_count = 0;
 	return r;
 }
 
diff --git a/drivers/scsi/mpt3sas/mpt3sas_base.h b/drivers/scsi/mpt3sas/mpt3sas_base.h
index 7dab579..cc4815c 100644
--- a/drivers/scsi/mpt3sas/mpt3sas_base.h
+++ b/drivers/scsi/mpt3sas/mpt3sas_base.h
@@ -93,6 +93,14 @@ 
 /* CoreDump: Default timeout */
 #define MPT3SAS_DEFAULT_COREDUMP_TIMEOUT_SECONDS	(15) /*15 seconds*/
 #define MPT3SAS_COREDUMP_LOOP_DONE                     (0xFF)
+#define MPT3SAS_TIMESYNC_TIMEOUT_SECONDS		(10) /* 10 seconds */
+#define MPT3SAS_TIMESYNC_UPDATE_INTERVAL		(900) /* 15 minutes */
+#define MPT3SAS_TIMESYNC_UNIT_MASK			(0x80) /* bit 7 */
+#define MPT3SAS_TIMESYNC_MASK				(0x7F) /* 0 - 6 bits */
+#define SECONDS_PER_MIN					(60)
+#define SECONDS_PER_HOUR				(3600)
+#define MPT3SAS_COREDUMP_LOOP_DONE			(0xFF)
+#define MPI26_SET_IOC_PARAMETER_SYNC_TIMESTAMP		(0x81)
 
 /*
  * Set MPT3SAS_SG_DEPTH value based on user input.
@@ -405,7 +413,7 @@  struct Mpi2ManufacturingPage11_t {
 	u16	HostTraceBufferMaxSizeKB;	/* 50h */
 	u16	HostTraceBufferMinSizeKB;	/* 52h */
 	u8	CoreDumpTOSec;			/* 54h */
-	u8	Reserved8;			/* 55h */
+	u8	TimeSyncInterval;		/* 55h */
 	u16	Reserved9;			/* 56h */
 	__le32	Reserved10;			/* 58h */
 };
@@ -1113,6 +1121,8 @@  typedef void (*MPT3SAS_FLUSH_RUNNING_CMDS)(struct MPT3SAS_ADAPTER *ioc);
  * @cpu_msix_table_sz: table size
  * @total_io_cnt: Gives total IO count, used to load balance the interrupts
  * @ioc_coredump_loop: will have non-zero value when FW is in CoreDump state
+ * @timestamp_update_count: Counter to fire timeSync command
+ * time_sync_interval: Time sync interval read from man page 11
  * @high_iops_outstanding: used to load balance the interrupts
  *				within high iops reply queues
  * @msix_load_balance: Enables load balancing of interrupts across
@@ -1308,6 +1318,8 @@  struct MPT3SAS_ADAPTER {
 	MPT3SAS_FLUSH_RUNNING_CMDS schedule_dead_ioc_flush_running_cmds;
 	u32             non_operational_loop;
 	u8              ioc_coredump_loop;
+	u32		timestamp_update_count;
+	u32		time_sync_interval;
 	atomic64_t      total_io_cnt;
 	atomic64_t	high_iops_outstanding;
 	bool            msix_load_balance;