From owner-svn-src-all@freebsd.org Wed Jul 19 15:39:02 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 ABDFACFC00A; Wed, 19 Jul 2017 15:39:02 +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 8634884409; Wed, 19 Jul 2017 15:39:02 +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 v6JFd1EG098777; Wed, 19 Jul 2017 15:39:01 GMT (envelope-from ken@FreeBSD.org) Received: (from ken@localhost) by repo.freebsd.org (8.15.2/8.15.2/Submit) id v6JFd1bn098775; Wed, 19 Jul 2017 15:39:01 GMT (envelope-from ken@FreeBSD.org) Message-Id: <201707191539.v6JFd1bn098775@repo.freebsd.org> X-Authentication-Warning: repo.freebsd.org: ken set sender to ken@FreeBSD.org using -f From: "Kenneth D. Merry" Date: Wed, 19 Jul 2017 15:39:01 +0000 (UTC) To: src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org Subject: svn commit: r321207 - in head/sys/dev: mpr mps X-SVN-Group: head X-SVN-Commit-Author: ken X-SVN-Commit-Paths: in head/sys/dev: mpr mps X-SVN-Commit-Revision: 321207 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: Wed, 19 Jul 2017 15:39:02 -0000 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");