svn commit: r321207 - in head/sys/dev: mpr mps

[Kenneth D. Merry]

Author: ken
Date: Wed Jul 19 15:39:01 2017
New Revision: 321207
URL: https://svnweb.freebsd.org/changeset/base/321207

Log:
  Fix spurious timeouts on commands sent to mps(4) and mpr(4) controllers.
  
  mps_wait_command() and mpr_wait_command() were using getmicrotime() to
  determine elapsed time when checking for a timeout in polled mode.
  getmicrotime() isn't guaranteed to monotonically increase, and that
  caused spurious timeouts occasionally.
  
  Switch to using getmicrouptime(), which does increase monotonically.
  This fixes the spurious timeouts in my test case.
  
  Reviewed by:	slm, scottl
  MFC after:	3 days
  Sponsored by:	Spectra Logic

Modified:
  head/sys/dev/mpr/mpr.c
  head/sys/dev/mps/mps.c

Modified: head/sys/dev/mpr/mpr.c
==============================================================================
--- head/sys/dev/mpr/mpr.c	Wed Jul 19 15:22:10 2017	(r321206)
+++ head/sys/dev/mpr/mpr.c	Wed Jul 19 15:39:01 2017	(r321207)
@@ -3286,9 +3286,17 @@ mpr_wait_command(struct mpr_softc *sc, struct mpr_comm
 	if (curthread->td_pflags & TDP_NOSLEEPING)
 #endif //__FreeBSD_version >= 1000029
 		sleep_flag = NO_SLEEP;
-	getmicrotime(&start_time);
+	getmicrouptime(&start_time);
 	if (mtx_owned(&sc->mpr_mtx) && sleep_flag == CAN_SLEEP) {
 		error = msleep(cm, &sc->mpr_mtx, 0, "mprwait", timeout*hz);
+		if (error == EWOULDBLOCK) {
+			/*
+			 * Record the actual elapsed time in the case of a
+			 * timeout for the message below.
+			 */
+			getmicrouptime(&cur_time);
+			timevalsub(&cur_time, &start_time);
+		}
 	} else {
 		while ((cm->cm_flags & MPR_CM_FLAGS_COMPLETE) == 0) {
 			mpr_intr_locked(sc);
@@ -3297,8 +3305,9 @@ mpr_wait_command(struct mpr_softc *sc, struct mpr_comm
 			else
 				DELAY(50000);
 		
-			getmicrotime(&cur_time);
-			if ((cur_time.tv_sec - start_time.tv_sec) > timeout) {
+			getmicrouptime(&cur_time);
+			timevalsub(&cur_time, &start_time);
+			if (cur_time.tv_sec > timeout) {
 				error = EWOULDBLOCK;
 				break;
 			}
@@ -3306,7 +3315,9 @@ mpr_wait_command(struct mpr_softc *sc, struct mpr_comm
 	}
 
 	if (error == EWOULDBLOCK) {
-		mpr_dprint(sc, MPR_FAULT, "Calling Reinit from %s\n", __func__);
+		mpr_dprint(sc, MPR_FAULT, "Calling Reinit from %s, timeout=%d,"
+		    " elapsed=%jd\n", __func__, timeout,
+		    (intmax_t)cur_time.tv_sec);
 		rc = mpr_reinit(sc);
 		mpr_dprint(sc, MPR_FAULT, "Reinit %s\n", (rc == 0) ? "success" :
 		    "failed");

Modified: head/sys/dev/mps/mps.c
==============================================================================
--- head/sys/dev/mps/mps.c	Wed Jul 19 15:22:10 2017	(r321206)
+++ head/sys/dev/mps/mps.c	Wed Jul 19 15:39:01 2017	(r321207)
@@ -2551,10 +2551,18 @@ mps_wait_command(struct mps_softc *sc, struct mps_comm
 	 */
 	if (curthread->td_no_sleeping != 0)
 		sleep_flag = NO_SLEEP;
-	getmicrotime(&start_time);
+	getmicrouptime(&start_time);
 	if (mtx_owned(&sc->mps_mtx) && sleep_flag == CAN_SLEEP) {
 		cm->cm_flags |= MPS_CM_FLAGS_WAKEUP;
 		error = msleep(cm, &sc->mps_mtx, 0, "mpswait", timeout*hz);
+		if (error == EWOULDBLOCK) {
+			/*
+			 * Record the actual elapsed time in the case of a
+			 * timeout for the message below.
+			 */
+			getmicrouptime(&cur_time);
+			timevalsub(&cur_time, &start_time);
+		}
 	} else {
 		while ((cm->cm_flags & MPS_CM_FLAGS_COMPLETE) == 0) {
 			mps_intr_locked(sc);
@@ -2563,8 +2571,9 @@ mps_wait_command(struct mps_softc *sc, struct mps_comm
 			else
 				DELAY(50000);
 		
-			getmicrotime(&cur_time);
-			if ((cur_time.tv_sec - start_time.tv_sec) > timeout) {
+			getmicrouptime(&cur_time);
+			timevalsub(&cur_time, &start_time);
+			if (cur_time.tv_sec > timeout) {
 				error = EWOULDBLOCK;
 				break;
 			}
@@ -2572,7 +2581,9 @@ mps_wait_command(struct mps_softc *sc, struct mps_comm
 	}
 
 	if (error == EWOULDBLOCK) {
-		mps_dprint(sc, MPS_FAULT, "Calling Reinit from %s\n", __func__);
+		mps_dprint(sc, MPS_FAULT, "Calling Reinit from %s, timeout=%d,"
+		    " elapsed=%jd\n", __func__, timeout,
+		    (intmax_t)cur_time.tv_sec);
 		rc = mps_reinit(sc);
 		mps_dprint(sc, MPS_FAULT, "Reinit %s\n", (rc == 0) ? "success" :
 		    "failed");