From owner-svn-src-all@freebsd.org Mon Jul 24 14:42:47 2017 Return-Path: Delivered-To: svn-src-all@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 4A924C7F96F; Mon, 24 Jul 2017 14:42:47 +0000 (UTC) (envelope-from ken@FreeBSD.org) Received: from repo.freebsd.org (repo.freebsd.org [IPv6:2610:1c1:1:6068::e6a:0]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 254936A7EC; Mon, 24 Jul 2017 14:42:47 +0000 (UTC) (envelope-from ken@FreeBSD.org) Received: from repo.freebsd.org ([127.0.1.37]) by repo.freebsd.org (8.15.2/8.15.2) with ESMTP id v6OEgjUg038582; Mon, 24 Jul 2017 14:42:45 GMT (envelope-from ken@FreeBSD.org) Received: (from ken@localhost) by repo.freebsd.org (8.15.2/8.15.2/Submit) id v6OEgjpW038580; Mon, 24 Jul 2017 14:42:45 GMT (envelope-from ken@FreeBSD.org) Message-Id: <201707241442.v6OEgjpW038580@repo.freebsd.org> X-Authentication-Warning: repo.freebsd.org: ken set sender to ken@FreeBSD.org using -f From: "Kenneth D. Merry" Date: Mon, 24 Jul 2017 14:42:45 +0000 (UTC) To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-stable@freebsd.org, svn-src-stable-10@freebsd.org Subject: svn commit: r321416 - in stable/10/sys/dev: mpr mps X-SVN-Group: stable-10 X-SVN-Commit-Author: ken X-SVN-Commit-Paths: in stable/10/sys/dev: mpr mps X-SVN-Commit-Revision: 321416 X-SVN-Commit-Repository: base MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit X-BeenThere: svn-src-all@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: "SVN commit messages for the entire src tree \(except for " user" and " projects" \)" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 24 Jul 2017 14:42:47 -0000 Author: ken Date: Mon Jul 24 14:42:45 2017 New Revision: 321416 URL: https://svnweb.freebsd.org/changeset/base/321416 Log: MFC r321207: ------------------------------------------------------------------------ r321207 | ken | 2017-07-19 09:39:01 -0600 (Wed, 19 Jul 2017) | 14 lines 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 Sponsored by: Spectra Logic Modified: stable/10/sys/dev/mpr/mpr.c stable/10/sys/dev/mps/mps.c Directory Properties: stable/10/ (props changed) Modified: stable/10/sys/dev/mpr/mpr.c ============================================================================== --- stable/10/sys/dev/mpr/mpr.c Mon Jul 24 14:42:43 2017 (r321415) +++ stable/10/sys/dev/mpr/mpr.c Mon Jul 24 14:42:45 2017 (r321416) @@ -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: stable/10/sys/dev/mps/mps.c ============================================================================== --- stable/10/sys/dev/mps/mps.c Mon Jul 24 14:42:43 2017 (r321415) +++ stable/10/sys/dev/mps/mps.c Mon Jul 24 14:42:45 2017 (r321416) @@ -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");